Незакрытые вызовы WCF начинают давать сбой через 2 минуты после обновления TLS 1.2 - ServicePointManager.SecurityProtocol изменяется - PullRequest
0 голосов
/ 15 января 2019

У меня запущена служба .NET Windows, в которой есть поток, который вызывает службу WCF с использованием wsHttpBinding с TransportWithMessageCredential безопасностью. Мы недавно переместили сервер WCF, и теперь он поддерживает только TLS 1.2, и обновили клиент службы Windows для принудительной установки TLS 1.2 (поскольку это .NET 4.0), используя ServicePointManager.SecurityProtocol = (SecurityProtocolType)3072;

Поток службы Windows вызывает службу WCF в цикле do ... while каждые 2 часа.

do
{
    GetUpdates();
}
while (!_syncEvents.ExitThreadEvent.WaitOne(_interval, true));

...

private void GetUpdates()
{
    MerchantProcessingClient svc = new MerchantProcessingClient();

    try
    {
        int lastProcessedBatch = facility.GetLastBatchRetrieved();

        bool alreadyProcessedMostRecentBatch = svc.IsFacilitysMostRecentBatch(_facilityID, lastProcessedBatch);

        if (!alreadyProcessedMostRecentBatch)
        {
            MPResultOfSettledPaymentsResult mpResult = svc.GetSettledPayments2(_facilityID, lastProcessedBatch);

            //Continues to process the response - never calls svc.Close()

Когда служба Windows запускается, вызовы WCF выполняются без ошибок, но при следующем запуске через 2 часа и каждый раз после этого он получает следующее исключение:

System.ServiceModel.CommunicationException: An error occurred while making the HTTP request to https://example.org/MerchantProcessing.svc. This could be due to the fact that the server certificate is not configured properly with HTTP.SYS in the HTTPS case. This could also be caused by a mismatch of the security binding between the client and the server. ---> System.Net.WebException: The underlying connection was closed: An unexpected error occurred on a send. ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.FixedSizeReader.ReadPacket(Byte[] buffer, Int32 offset, Int32 count)
   at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest)
   at System.Net.Security.SslState.CheckCompletionBeforeNextReceive(ProtocolToken message, AsyncProtocolRequest asyncRequest)
   at System.Net.Security.SslState.ForceAuthentication(Boolean receiveFirst, Byte[] buffer, AsyncProtocolRequest asyncRequest)
   at System.Net.Security.SslState.ProcessAuthentication(LazyAsyncResult lazyResult)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
  at System.Net.TlsStream.ProcessAuthentication(LazyAsyncResult result)
   at System.Net.TlsStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.ConnectStream.WriteHeaders(Boolean async)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.GetResponse()
   at System.ServiceModel.Channels.HttpChannelFactory`1.HttpRequestChannel.HttpChannelRequest.WaitForReply(TimeSpan timeout)
   --- End of inner exception stack trace ---

Server stack trace: 
   at System.ServiceModel.Channels.HttpChannelUtilities.ProcessGetResponseWebException(WebException webException, HttpWebRequest request, HttpAbortReason abortReason)
   at System.ServiceModel.Channels.HttpChannelFactory`1.HttpRequestChannel.HttpChannelRequest.WaitForReply(TimeSpan timeout)
   at System.ServiceModel.Channels.RequestChannel.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Channels.SecurityChannelFactory`1.SecurityRequestChannel.Request(Message message, TimeSpan timeout)
   at System.ServiceModel.Security.SecuritySessionSecurityTokenProvider.DoOperation(SecuritySessionOperation operation, EndpointAddress target, Uri via, SecurityToken currentToken, TimeSpan timeout)
   at System.ServiceModel.Security.SecuritySessionSecurityTokenProvider.GetTokenCore(TimeSpan timeout)
   at System.IdentityModel.Selectors.SecurityTokenProvider.GetToken(TimeSpan timeout)
   at System.ServiceModel.Security.SecuritySessionClientSettings`1.ClientSecuritySessionChannel.OnOpen(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.OnOpen(TimeSpan timeout)
   at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.CallOpenOnce.System.ServiceModel.Channels.ServiceChannel.ICallOnce.Call(ServiceChannel channel, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.CallOnceManager.CallOnce(TimeSpan timeout, CallOnceManager cascade)
   at System.ServiceModel.Channels.ServiceChannel.EnsureOpened(TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)

Exception rethrown at [0]: 
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at Data.MerchantProcessingService.IMerchantProcessing.IsFacilitysMostRecentBatch(Guid facilityID, Int32 facilityBatchHistoryID)
   at WindowsService.ProcessMerchantServices.GetUpdates()

Если мы обновляем интервал для вызова службы каждые 60 секунд, а не каждые 2 часа, исключение не регистрируется примерно через 10 минут. Если мы изменим его на 120 секунд, он получит исключение со 2-й попытки.

Таким образом, кажется, что что-то удерживает токен безопасности или пытается повторно использовать соединение или что-то еще, и если оно не делает этого в течение некоторого интервала менее 2 минут, срок действия истекает. receivetimeout сервера установлен на 90 секунд, поэтому я подозреваю, что это предел. У нас уже было обновление, ожидающее выхода, которое вызывает svc.Close на прокси WCF, но я не понимаю, как или где что-то сохраняется, когда в каждой итерации создается новый MerchantProcessingClient. Я также не уверен, почему мы не видим этого в родственном WPF-приложении службы Windows, которое использует тот же прокси Data.MerchantProcessingService.IMerchantProcessing для вызова службы. Что здесь происходит?


Обновление:

Сузил это немного больше, но я все еще в замешательстве. Я исключил из сервера receiveTimeout - это не связано. Я добавил следующую запись в службу Windows:

logger.Debug("ServicePointManager.SecurityProtocol = " + (int)System.Net.ServicePointManager.SecurityProtocol);

bool alreadyProcessedMostRecentBatch = svc.IsFacilitysMostRecentBatch(_facilityID, lastProcessedBatch);

и наблюдал за трафиком на наш WCF-сервер в Wireshark, пока он работал. Wireshark показывает первый вызов с использованием Tls 1.2 и второй вызов, который не удается с помощью Tls v1! Это объясняет исключение, поскольку сервер не поддерживает v1. До первого звонка выше логирования логов:

ServicePointManager.SecurityProtocol = 240    //Ssl3 & Tls

Так что моя строка ServicePointManager.SecurityProtocol = (SecurityProtocolType)3072; в моем классе приложения Settings в библиотеке классов, содержащей MerchantProcessingClient, либо не применена, либо перезаписана к этому моменту, я предполагаю последнее. Хорошо, но как же тогда первый звонок с использованием Tls 1.2? ServicePointManager.SecurityProtocol перекрывается чем-то и только в первый раз?

Тогда перед вторым звонком журнал показывает это:

ServicePointManager.SecurityProtocol = 192    //Tls

Затем я попытался установить SecurityProtocol перед каждым вызовом службы следующим образом:

logger.Debug("ServicePointManager.SecurityProtocol = " + (int)System.Net.ServicePointManager.SecurityProtocol);

System.Net.ServicePointManager.SecurityProtocol = (System.Net.SecurityProtocolType)3072;

logger.Debug("New ServicePointManager.SecurityProtocol = " + (int)System.Net.ServicePointManager.SecurityProtocol);

bool alreadyProcessedMostRecentBatch = svc.IsFacilitysMostRecentBatch(_facilityID, lastProcessedBatch);

Это исключает исключение, но интересным является журнал за первые две итерации:

ServicePointManager.SecurityProtocol = 192
New ServicePointManager.SecurityProtocol = 3072
/* service call succeeds here, Wireshark shows Tls 1.2 */

ServicePointManager.SecurityProtocol = 192
New ServicePointManager.SecurityProtocol = 3072
/* 2nd service call succeeds here, Wireshark shows Tls 1.2 */

На 2-й итерации SecurityProtocol снова возвращается в 192! Что-то еще, что я на 95% уверен, что наш код явно не является, - это изменение SecurityProtocol обратно на Tls v1. Другие потоки в этой службе Windows вызывают другую службу WCF, которая может не поддерживать Tls 1.2, параллельно через свои собственные интервалы, поэтому я подумал, что, возможно, это внутренне автоматически понижает SecurityProtocol при вызове этих служб, но это не так объясните, как первый вызов всегда выполнялся успешно или как все вызовы в исходном коде выполняются успешно при установке интервала на 1 минуту вместо 2. Я сбит с толку. Наш текущий план состоит в том, чтобы обновить до .NET 4.6.2 как можно скорее, но все еще пытаемся понять это. Слишком много неизвестных.

...