Thursday, November 8, 2012

Time mismatch between WCF client and service

Recently we faced with interesting problem. We have Sharepoint site which uses WCF for communications via BizTalk with other business applications. Starting from one morning some requests (but not all) to BizTalk failed. In production we have 2 WFE servers, so at first I checked event logs on both of them. In WFE1 everything was Ok, but on WFE2 I found the following error:

The security timestamp is invalid because its creation time ('2012-11-07T11:48:14.507Z') is in the
future. Current time is '2012-11-07T11:42:42.605Z' and allowed clock skew is
'00:05:00'.
Server stack trace:
   at System.ServiceModel.Security.SecurityTimestamp.ValidateFreshness(TimeSpan
timeToLive, TimeSpan allowedClockSkew)
   at System.ServiceModel.Security.SecurityTimestamp.ValidateRangeAndFreshness(TimeSpan
timeToLive, TimeSpan allowedClockSkew)
   at System.ServiceModel.Security.ReceiveSecurityHeader.ReadTimestamp(XmlDictionaryReader
reader)
   at System.ServiceModel.Security.ReceiveSecurityHeader.ExecuteFullPass(XmlDictionaryReader reader)
   at System.ServiceModel.Security.ReceiveSecurityHeader.Process(TimeSpan timeout,
ChannelBinding channelBinding, ExtendedProtectionPolicy extendedProtectionPolicy)
   at System.ServiceModel.Security.MessageSecurityProtocol.ProcessSecurityHeader(ReceiveSecurityHeader securityHeader, Message& message, SecurityToken requiredSigningToken, TimeSpan timeout, SecurityProtocolCorrelationState[] correlationStates)

So it says that difference between current date time on WFE2 and current date time on BT server is more than 5 minutes which is default maximum allowed difference between local times on the client and service. System clock on WFE2 really showed time which was late on approximately 6 minutes. On WFE1 system time was synchronized with domain time. So requests processed on WFE1 worked successfully, but requests from WFE2 failed. I changed the time on WFE2 manually and after that requests became working.

The problem was that because of some reason system time on WFE2 was unsynchronized with domain controller time. In System category of the event log I found the record which said that Windows changed local time on 1 minute back. As time was unsynchronized already, from this morning difference became more than 5 minutes. That’s why the problem didn’t appear immediately. I will update this post once will get the reason of time unsynchronizing.

No comments:

Post a Comment