Asked by:
OCS2007 R2 to Exchange 2007UM connectivity problems

Question
-
Hello,
I am having difficulty configuring OCS 2007 R2 to work with Exchange 2007 UM. When I attempt to call my Exchange UM voice mail I get a fast busy signal. I am using a Windows 2008 Enterprise CA. All of the sytems involved are part of the same Active Directory Domain/Forest. I have confirmed all of the certificate configurations as outline in the OCS R2 Configuriong Enterprise Voice Docs.
I have appended an OCS trace along with an network monitor trace. I would appreciate any insight into this.
Thanks
BillOCS Server Trace Logs:
TL_INFO(TF_CONNECTION) [0]0690.0834::10/11/2009-02:46:36.076.00012269 (SIPStack,SIPAdminLog::TraceConnectionRecord:SIPAdminLog.cpp(161))$$begin_record
LogType: connection
Severity: information
Text: TLS negotiation started
Local-IP: 10.1.16.70:51651
Peer-IP: 10.1.16.51:5061
Peer-FQDN: EXCHANGE.mydomain.com
Connection-ID: 0x4D01
Transport: TLS
$$end_record
TL_ERROR(TF_CONNECTION) [0]0690.0834::10/11/2009-02:46:36.080.000133b9 (SIPStack,SIPAdminLog::TraceConnectionRecord:SIPAdminLog.cpp(157))$$begin_record
LogType: connection
Severity: error
Text: Outbound TLS negotiation failed
Local-IP: 10.1.16.70:51651
Peer-IP: 10.1.16.51:5061
Peer-FQDN: EXCHANGE.mydomain.com
Connection-ID: 0x4D01
Transport: TLS
Result-Code: 0x80090325
$$end_record
TL_ERROR(TF_CONNECTION) [0]0690.0834::10/11/2009-02:46:36.080.000133d3 (SIPStack,SIPAdminLog::TraceConnectionRecord:SIPAdminLog.cpp(157))$$begin_record
LogType: connection
Severity: error
Text: The connection was closed before TLS negotiation completed. Did the remote peer accept our certificate?
Local-IP: 10.1.16.70:51651
Peer-IP: 10.1.16.51:5061
Peer-FQDN: EXCHANGE.mydomain.com
Connection-ID: 0x4D01
Transport: TLS
$$end_record
TL_INFO(TF_DIAG) [1]0690.0C18::10/11/2009-02:46:36.080.0001344a (SIPStack,SIPAdminLog::TraceDiagRecord:SIPAdminLog.cpp(144))$$begin_record
LogType: diagnostic
Severity: information
Text: Response successfully routed
SIP-Start-Line: SIP/2.0 183 Session Progress
SIP-Call-ID: 7fdd0ffc1c3647e3b2d5e3e59dbaedf6
SIP-CSeq: 1 INVITE
Peer: 10.1.16.101:55428
Data: destination="EMAIL REMOVED"
$$end_record
TL_ERROR(TF_DIAG) [0]0690.0834::10/11/2009-02:46:36.080.0001346e (SIPStack,SIPAdminLog::TraceDiagRecord:SIPAdminLog.cpp(140))$$begin_record
LogType: diagnostic
Severity: error
Text: Message was not sent because the connection was closed
SIP-Start-Line: INVITE sip:EMAIL REMOVED:5061;transport=tls;maddr=EXCHANGE.mydomain.com SIP/2.0
SIP-Call-ID: 7fdd0ffc1c3647e3b2d5e3e59dbaedf6
SIP-CSeq: 1 INVITE
Peer: EXCHANGE.mydomain.com:5061
$$end_record
TL_INFO(TF_PROTOCOL) [1]0690.0C18::10/11/2009-02:46:36.080.000134cb (SIPStack,SIPAdminLog::TraceProtocolRecord:SIPAdminLog.cpp(122))$$begin_record
Instance-Id: 00000564
Direction: outgoing;source="local"
Peer: 10.1.16.101:55428
Message-Type: response
Start-Line: SIP/2.0 183 Session Progress
From: "William T. Holmes"<sip:EMAIL REMOVED>;tag=070d640f7e;epid=9eae7efce0
To: <sip:EMAIL REMOVED;opaque=app:voicemail>
CSeq: 1 INVITE
Call-ID: 7fdd0ffc1c3647e3b2d5e3e59dbaedf6
Proxy-Authentication-Info: Kerberos rspauth="602306092A864886F71201020201011100FFFFFFFFF84A01E6454EE1AB91F37AFFD0473E58", srand="811C58E5", snum="240", opaque="C2B36706", qop="auth", targetname="sip/OCSERVER.mydomain.com", realm="SIP Communications Service"
Content-Length: 0
Via: SIP/2.0/TLS 10.1.16.101:55428;ms-received-port=55428;ms-received-cid=C00
Ms-Forking: Active
Server: http%3A%2F%2Fwww.microsoft.com%2FLCS%2FDefaultRouting(Microsoft Office Communications Server 2007 R2 3.5.6907.0)
Message-Body: –
$$end_record
TL_WARN(TF_DIAG) [0]0690.0834::10/11/2009-02:46:36.080.000135c9 (SIPStack,SIPAdminLog::TraceDiagRecord:SIPAdminLog.cpp(142))$$begin_record
LogType: diagnostic
Severity: warning
Text: Routing error occurred; check Result-Code field for more information
Result-Code: 0x80004004 E_ABORT
SIP-Start-Line: INVITE sip:EMAIL REMOVED:5061;transport=tls;maddr=EXCHANGE.mydomain.com SIP/2.0
SIP-Call-ID: 7fdd0ffc1c3647e3b2d5e3e59dbaedf6
SIP-CSeq: 1 INVITE
Peer: EXCHANGE.mydomain.com:5061
$$end_record
OCS Network Monitor:
195 34.121094 {SMB:34, UDP:33, IPv4:32} EXCHANGE-UM 10.1.16.255 BROWSER BROWSER:Host Announcement, ServerName = EXCHANGE-UM
339 44.183594 {TCP:49, IPv4:48} 10.1.16.70 EXCHANGE-UM TCP TCP:Flags=......S., SrcPort=51652, DstPort=5061, PayloadLen=0, Seq=3658775084, Ack=0, Win=8192 ( Negotiating scale factor 0x8 ) = 8192
342 44.184571 {TCP:49, IPv4:48} EXCHANGE-UM 10.1.16.70 TCP TCP:Flags=...A..S., SrcPort=5061, DstPort=51652, PayloadLen=0, Seq=1637903551, Ack=3658775085, Win=8192 ( Negotiated scale factor 0x8 ) = 2097152
343 44.184571 {TCP:49, IPv4:48} 10.1.16.70 EXCHANGE-UM TCP TCP:Flags=...A...., SrcPort=51652, DstPort=5061, PayloadLen=0, Seq=3658775085, Ack=1637903552, Win=513 (scale factor 0x8) = 131328
344 44.184571 {SSL:50, TCP:49, IPv4:48} 10.1.16.70 EXCHANGE-UM SSL SSL: Client Hello.
345 44.186524 {SSL:50, TCP:49, IPv4:48} EXCHANGE-UM 10.1.16.70 SSL SSL: Server Hello. Certificate.
346 44.186524 {TCP:49, IPv4:48} EXCHANGE-UM 10.1.16.70 TCP TCP:[Continuation to #345]Flags=...A...., SrcPort=5061, DstPort=51652, PayloadLen=1460, Seq=1637905012 - 1637906472, Ack=3658775215, Win=513 (scale factor 0x8) = 131328
347 44.186524 {TCP:49, IPv4:48} 10.1.16.70 EXCHANGE-UM TCP TCP:Flags=...A...., SrcPort=51652, DstPort=5061, PayloadLen=0, Seq=3658775215, Ack=1637906472, Win=513 (scale factor 0x8) = 131328
350 44.186524 {TCP:49, IPv4:48} EXCHANGE-UM 10.1.16.70 TCP TCP:[Continuation to #345]Flags=...AP..., SrcPort=5061, DstPort=51652, PayloadLen=1241, Seq=1637906472 - 1637907713, Ack=3658775215, Win=513 (scale factor 0x8) = 131328
353 44.193360 {SSL:50, TCP:49, IPv4:48} 10.1.16.70 EXCHANGE-UM SSL SSL: Certificate.
354 44.193360 {TCP:49, IPv4:48} EXCHANGE-UM 10.1.16.70 TCP TCP:Flags=...A...., SrcPort=5061, DstPort=51652, PayloadLen=0, Seq=1637907713, Ack=3658778135, Win=513 (scale factor 0x8) = 131328
355 44.193360 {TCP:49, IPv4:48} 10.1.16.70 EXCHANGE-UM TCP TCP:[Continuation to #353]Flags=...AP..., SrcPort=51652, DstPort=5061, PayloadLen=1157, Seq=3658778135 - 3658779292, Ack=1637907713, Win=508 (scale factor 0x8) = 130048
356 44.201172 {SSL:50, TCP:49, IPv4:48} EXCHANGE-UM 10.1.16.70 SSL SSL: Change Cipher Spec. Encrypted Handshake Message.
357 44.201172 {TCP:49, IPv4:48} 10.1.16.70 EXCHANGE-UM TCP TCP:Flags=...A.R.., SrcPort=51652, DstPort=5061, PayloadLen=0, Seq=3658779292, Ack=1637907772, Win=0 (scale factor 0x8) = 0
526 72.462891 RTCSrv.exe {SSL:54, TCP:53, IPv4:48} EXCHANGE-UM 10.1.16.70 SSL SSL: Application Data.
527 72.462891 RTCSrv.exe {SSL:54, TCP:53, IPv4:48} 10.1.16.70 EXCHANGE-UM SSL SSL: Application Data.
529 72.652344 RTCSrv.exe {TCP:53, IPv4:48} EXCHANGE-UM 10.1.16.70 TCP TCP:Flags=...A...., SrcPort=20009, DstPort=5061, PayloadLen=0, Seq=2173082437, Ack=4159537833, Win=511
Sunday, October 11, 2009 3:23 AM
All replies
-
Do you still have the default self-signed certificate in use on the Exchange server(s) or have you replaced them with certificates issued by the same Enterprise CA used for the OCS server certificates?
Jeff Schertz, PointBridge | MVP | MCITP: Enterprise Messaging | MCTS: OCSSunday, October 11, 2009 1:09 PMModerator -
Hi,
Thanks for your reply. This problem is really driving me nuts.
I have replaced the self-signed certificates with cerificates issued by my Enterprise Subordinate CA. I have also verified that the certificates on the OCS servers and the Exchange UM servers all have valid Certificte chains back to my enterprise CA via my Subordinate CA.
BillSunday, October 11, 2009 4:32 PM -
I have seen this before.
By default, when we use the Certificate Wizard to create Certificate requst (Front End Server), it will insert SIP.domain as SAN. When I had the same issue, it was resolved by re-issuing the FE certificate w/o SAN.
Will you please try this and let us know?
DragoSunday, October 11, 2009 5:27 PM -
Hi,
I pulled the sip domain out but now I can log into Office Communicator.
BillMonday, October 12, 2009 12:49 AM -
You can or cannot login to Communicator? If you cannot, what is the error message?
Let me make clear - you re-issued the certificate by:
1. Generating new offline request
2. You checked "Include Client EKU in the certificate request"
3. In the box "Subject Name" you have FQDN of your front end server
4. The box "Subject Alternative Name" is empty
5. After the new certificate was issued, you assigned it using the Certificate wizard (Process an offline certificate request and import the certificate)
6. You assigned the certificate to the HTTP server on the front end server
7. The Front End was restarted
8. The Office Communications Server log (Event viewer) is clean of errors
I am sorry for the questions - it is easy to overlook something when frustrated :-)Monday, October 12, 2009 3:08 AM -
Hi Again,
I followed the procdeure as outlined. With out the sip.mydomain.com in the SAN attribute Office Communicator Responds with the following error message when attempting to sign on.
Office Communicator will not sign on and gives the following error message: There was a problem verifying the certificate from the server. Please contact your system administrator. That's Me :-).
The sign in problem on OCS was due to the fact that my SRV records were pointing to the sip.mydomain.com name which is no longer on my SAN certificate. I updated the records to point to my front-end name instead ocs.mydomain.com.
Now I have a single name on the cerificate ocserver.mydomain.com. I have assigned it to both the ocserver (using the certificate wizard) and to my IIS server using the IIS7 Mangement Console (set https binding to use the new certificate)
Try to connect to my Voice Mail on Exchange I get a fast busy. On the exchagne UM I get the followin Event fro Unified Messanging.
Log Name: Application
Source: MSExchange Unified Messaging
Date: 10/12/2009 11:52:24 PM
Event ID: 1113
Task Category: UMService
Level: Warning
Keywords: Classic
User: N/A
Computer: EXCHANGE.mydomain.com
Description:
The Unified Messaging server failed to exchange the required certificates with an IP gateway to enable Transport Layer Security (TLS) for an incoming call. Check that this is a configured TLS peer and that the correct certificates are being used. More information: A TLS failure occurred because the remote end disconnected while TLS negotiation was in progress. The error Code was -2146233088 and the message was Unknown error (0x80131500).
I have also seen this warning in the exchange UM Log:
Log Name: Application
Source: MSExchange Unified Messaging
Date: 10/12/2009 11:58:51 PM
Event ID: 1088
Task Category: UMService
Level: Warning
Keywords: Classic
User: N/A
Computer: EXCHANGE.mydomain.com
Description:
The IP gateway or IP-PBX "ocserver.mydomain.com" did not respond to a SIP OPTIONS request from the Unified Messaging server. The error code that was returned is "0" and the error text is ":This operation has timed out.".
I also repeated the procedure doing an online request with same results. That is I used the certificate wizard that comes embedded in the OCS 2007 R2 Mangement Console.
In each case a I restarted the OCS front-end server with no errors recorded.
It all points to a cert issue but I am at a loss as to the exact nature of this. I have issued all the cerficates from my own CA. I have checked all the certs for the validity as well as their chaning back to my root CA.
Thanks
BillTuesday, October 13, 2009 4:01 AM -
All this points to Certificate issue. Check this posts:
http://social.technet.microsoft.com/forums/en-US/exchangesvrunifiedmessaging/thread/f842a5bf-e899-47dc-aa90-d28517affbb1/
http://social.microsoft.com/Forums/en-US/ucintegrationwithexchange/thread/da52e8da-b7d6-464b-b018-15535b4b2d01
Also, will you verufy toye UM Dial plan is set to secured? The server's time day and year match?
Drago- Proposed as answer by Gavin-ZhangModerator Friday, October 23, 2009 8:15 AM
Tuesday, October 13, 2009 11:36 AM -
Hello,
I have gone over this again and I am really at a loss.
I have reissued both of my certificates without using any SAN names at all. The subject names of my cerificates match the full qualified domain names of my OCS and Exchange UM servers. I have checked my DNS to be sure that both forward and reverse lookups are correct.
I have the UM dialplan set to secured. (not sip secured although I tried that as well) and I am still getting
TL_ERROR(TF_CONNECTION) [0]0298.12F4::10/14/2009-04:22:57.810.00005912 (SIPStack,SIPAdminLog::TraceConnectionRecord:SIPAdminLog.cpp(157))$$begin_record
LogType
Severity
Text
Local-IP
Peer-IP
Peer-FQDN
Connection-ID
Transport
Result-Code
$$end_record
: 0x80004005 E_FAIL: TLS: 0x600: EXCHANGE.mydomain.com: 10.16.30.51:5061: 10.16.30.70:51388: Outbound TLS negotiation failed: error: connection I know this is a cerificate error but I can't determine why its happening. Is there somthing more that I need to enable on my exchange server to allow certificate auth to work correctly?Wednesday, October 14, 2009 4:53 AM -
There is also a CRL (Certificate Revocation List) check duting the TLS negotiation. Check this: http://technet.microsoft.com/en-us/library/cc759324(WS.10).aspx and make sure the latest CRL exist on Exchange in particular.
Drago- Proposed as answer by Gavin-ZhangModerator Friday, October 23, 2009 8:15 AM
Wednesday, October 14, 2009 1:02 PM -
Hi
Any update for your issue?
Regards!Friday, October 23, 2009 8:15 AMModerator