Call to an Web API works sometime, but usually get error about closed connection. Could the token validation be causing the issue?

2

UPDATE 4 Even More confused I thought I was onto something, but the same error keeps popping up. This solution seemed promising, but isn't 100%, but thought it might help someone narrow down what's wrong.

Steps:

  1. Restart API and Identity Server IIS Application Pools
  2. Get Access Token Via SoapUI using QA URL
  3. Hit API in QA with SoapUI
  4. Failure - Doesn't work (See below for this stacktrace)
  5. Hit API locally with SoapUI (Using same QA Identity Server URL)
  6. Local API URL returns expected data
  7. Hit API using QA URL using SoapUI (I'm just changing the endpoint in SoapUI)
  8. QA API URL returns expected data

I was able to repeat that 4 times before I would still get the Error when hitting QA. After restarting this process again, I can now get my QA environment to work without having to use the API locally. Any ideas what's going on? Seems to be a setup issue/proxy/certificate issue, but no idea how to debug that.

This is the error that I'm seeing now: Server Error in '/' Application. An existing connection was forcibly closed by the remote host Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code. Exception Details: System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host Source Error: An unhandled exception was generated during the execution of the current web request. Information regarding the origin and location of the exception can be identified using the exception stack trace below. Stack Trace:

[SocketException (0x2746): An existing connection was forcibly closed by the remote host]
   System.Net.Sockets.Socket.EndReceive(IAsyncResult asyncResult) +8156963
   System.Net.Sockets.NetworkStream.EndRead(IAsyncResult asyncResult) +48

[IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host.]
   System.Net.Security._SslStream.EndRead(IAsyncResult asyncResult) +8111720
   System.Net.TlsStream.EndRead(IAsyncResult asyncResult) +275
   System.Net.Connection.ReadCallback(IAsyncResult asyncResult) +45

[WebException: The underlying connection was closed: An unexpected error occurred on a receive.]
   System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult) +764
   System.Net.Http.HttpClientHandler.GetResponseCallback(IAsyncResult ar) +78

[HttpRequestException: An error occurred while sending the request.]

[AggregateException: One or more errors occurred.]
   System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification) +4451240
   Microsoft.IdentityModel.Protocols.<GetDocumentAsync>d__0.MoveNext() in c:\workspace\WilsonForDotNet45Release\src\Microsoft.IdentityModel.Protocol.Extensions\Configuration\HttpDocumentRetriever.cs:53

[IOException: Unable to get document from: https://securityeliqa.twcable.com/core/.well-known/openid-configuration]
   Microsoft.IdentityModel.Protocols.<GetDocumentAsync>d__0.MoveNext() in c:\workspace\WilsonForDotNet45Release\src\Microsoft.IdentityModel.Protocol.Extensions\Configuration\HttpDocumentRetriever.cs:59
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +13847892
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +61
   Microsoft.IdentityModel.Protocols.<GetAsync>d__0.MoveNext() in c:\workspace\WilsonForDotNet45Release\src\Microsoft.IdentityModel.Protocol.Extensions\Configuration\OpenIdConnectConfigurationRetriever.cs:81
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +13847892
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +61
   Microsoft.IdentityModel.Protocols.<GetConfigurationAsync>d__3.MoveNext() in c:\workspace\WilsonForDotNet45Release\src\Microsoft.IdentityModel.Protocol.Extensions\Configuration\ConfigurationManager.cs:0

[InvalidOperationException: IDX10803: Unable to create to obtain configuration from: 'https://securityeliqa.twcable.com/core/.well-known/openid-configuration'.]
   Microsoft.IdentityModel.Protocols.<GetConfigurationAsync>d__3.MoveNext() in c:\workspace\WilsonForDotNet45Release\src\Microsoft.IdentityModel.Protocol.Extensions\Configuration\ConfigurationManager.cs:212
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +13847892
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +61
   Microsoft.IdentityModel.Protocols.<GetConfigurationAsync>d__0.MoveNext() in c:\workspace\WilsonForDotNet45Release\src\Microsoft.IdentityModel.Protocol.Extensions\Configuration\ConfigurationManager.cs:0
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +13847892
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +61
   System.Runtime.CompilerServices.TaskAwaiter`1.GetResult() +31
   IdentityServer.WebApi.AccessTokenValidation.<<RetrieveMetadata>b__0>d__4.MoveNext() in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\Plumbing\DiscoveryDocumentIssuerSecurityTokenProvider.cs:123
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) +13847892
   System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) +61
   System.Runtime.CompilerServices.TaskAwaiter`1.GetResult() +31
   IdentityServer.WebApi.AccessTokenValidation.AsyncHelper.RunSync(Func`1 func) in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\Plumbing\AsyncHelper.cs:18
   IdentityServer.WebApi.AccessTokenValidation.DiscoveryDocumentIssuerSecurityTokenProvider.RetrieveMetadata() in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\Plumbing\DiscoveryDocumentIssuerSecurityTokenProvider.cs:141
   IdentityServer.WebApi.AccessTokenValidation.DiscoveryDocumentIssuerSecurityTokenProvider..ctor(String discoveryEndpoint, IdentityServerBearerTokenAuthenticationOptions options, ILoggerFactory loggerFactory) in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\Plumbing\DiscoveryDocumentIssuerSecurityTokenProvider.cs:43
   Owin.IdentityServerBearerTokenValidationAppBuilderExtensions.ConfigureLocalValidation(IdentityServerBearerTokenAuthenticationOptions options, ILoggerFactory loggerFactory) in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\IdentityServerBearerTokenValidationAppBuilderExtensions.cs:129
   Owin.IdentityServerBearerTokenValidationAppBuilderExtensions.UseIdentityServerBearerTokenAuthentication(IAppBuilder app, IdentityServerBearerTokenAuthenticationOptions options) in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\IdentityServerBearerTokenValidationAppBuilderExtensions.cs:39
   Company.WebApi.waAddressQualification.Startup.Configuration(IAppBuilder app) in e:\Source Code\GitHub\waDemo\Startup.cs:23

[TargetInvocationException: Exception has been thrown by the target of an invocation.]
   System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor) +0
   System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object[] parameters, Object[] arguments) +128
   System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture) +146
   Owin.Loader.<>c__DisplayClass12.<MakeDelegate>b__b(IAppBuilder builder) +93
   Owin.Loader.<>c__DisplayClass1.<LoadImplementation>b__0(IAppBuilder builder) +209
   Microsoft.Owin.Host.SystemWeb.OwinAppContext.Initialize(Action`1 startup) +843
   Microsoft.Owin.Host.SystemWeb.OwinBuilder.Build(Action`1 startup) +51
   Microsoft.Owin.Host.SystemWeb.OwinHttpModule.InitializeBlueprint() +101
   System.Threading.LazyInitializer.EnsureInitializedCore(T& target, Boolean& initialized, Object& syncLock, Func`1 valueFactory) +137
   Microsoft.Owin.Host.SystemWeb.OwinHttpModule.Init(HttpApplication context) +172
   System.Web.HttpApplication.RegisterEventSubscriptionsWithIIS(IntPtr appContext, HttpContext context, MethodInfo[] handlers) +618
   System.Web.HttpApplication.InitSpecial(HttpApplicationState state, MethodInfo[] handlers, IntPtr appContext, HttpContext context) +172
   System.Web.HttpApplicationFactory.GetSpecialApplicationInstance(IntPtr appContext, HttpContext context) +402
   System.Web.Hosting.PipelineRuntime.InitializeApplication(IntPtr appContext) +343

[HttpException (0x80004005): Exception has been thrown by the target of an invocation.]
   System.Web.HttpRuntime.FirstRequestInit(HttpContext context) +579
   System.Web.HttpRuntime.EnsureFirstRequestInit(HttpContext context) +112
   System.Web.HttpRuntime.ProcessRequestNotificationPrivate(IIS7WorkerRequest wr, HttpContext context) +712

Version Information: Microsoft .NET Framework Version:4.0.30319; ASP.NET Version:4.6.1055.0

UPDATE 3 Even More confused

At this point I believe it's the server that is cancelling my requests, but even with that I can't be 100% sure. Here are some additional data points:

  • Service is setup on both a Dev and QA box, Dev box gets the error about 1 out of 100 requests, QA, about 50% of the time.
  • The QA box has Identity Server setup as https behind a load balancer, Dev is http
  • The service setup mimics Identity Server where in QA it is https behind a load balancer, Dev is http
  • A set of three address in QA will usually have at least one address fail, I see the request in the server log for the two that work, shouldn't I see the third? If the third request is not in the server logs does that mean it never got there?
  • What really gets me is I can't seem to see an error anywhere but on the client, where the HttpClient.GetAsync call is made. If the server is cancelling the request, shouldn't there be a log for each one it cancels?
  • I've found in the Event log on on the windows server hosting the service errors about cancelling a task, however not all failed requests end up here? The operation was canceled. at System.Threading.CancellationToken.ThrowOperationCanceledException() at System.Web.Http.Owin.HttpMessageHandlerAdapter.d__13.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Web.Http.Owin.HttpMessageHandlerAdapter.d__0.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.TaskAwaiter.GetResult() at IdentityServer.WebApi.AccessTokenValidation.ScopeRequirementMiddleware.d__0.MoveNext() in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\Plumbing\ScopeRequirementMiddleware.cs:line 48 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Owin.Security.Infrastructure.AuthenticationMiddleware`1.d__0.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.TaskAwaiter.GetResult() at IdentityServer.WebApi.AccessTokenValidation.IdentityServerBearerTokenValidationMiddleware.d__6.MoveNext() in e:\Source Code\GitHub\IdentityServer\IdentityServer.WebApi.AccessTokenValidation\IdentityServerBearerTokenValidationMiddleware.cs:line 81 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContextStage.d__5.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContext.d__2.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.StageAsyncResult.End(IAsyncResult ar) at System.Web.HttpApplication.AsyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Original Questions

I'd like to know if I'm call my Demo API correctly, or if the API is causing me an issue. If I send three requests through at the same time I get the issue on at least one of the addresses I'm trying to process.

Update Number one

In the Inner Exception I'm getting the following message, I was able to capture a more complete error as follows: "The underlying connection was closed: An unexpected error occurred on a receive. ---> 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"

I'm using .NET 4.6.1 for both client and server side I'm not using a proxy. I'm able to successfully call the API about 1/3 of the time

I've experimented with the couple of different options in calling the service, the first was just wrapping the DemoApiClient in a lock, the next was to use Task Run with the async and await keywords and finally retrieving the token for authentication using Task Run or just calling it and having ConfigureAwait(false) listed on the await lines. I'm not sure if any of this matters, or if the server is just failing when called. The server isn't that complex, but I'd rather not post that code here. It does validate the token and then process an address, makes a couple of database calls and returns data found from the database.

UPDATE 2 I test with three addresses at a time, when I send them through SoapUI to the server all three are process fine, but with the .Net C# client using the code below only one of the three requests seem to make it to the server. I was expecting to see two stacktraces and one successful request, but the IIS log only shows one request coming in.

The code I'm using to call the API is here:

using Demo.IdentityServer.IdentityModel.Client;
using Newtonsoft.Json;
using PartnerPortal.Model;
using System;
using System.Configuration;
using System.Diagnostics;
using System.Net.Http;
using System.Linq;
using System.Collections.Generic;
using System.Threading.Tasks;

namespace DemoPortal.Client
{
    public static class DemoApiClient
    {
        public readonly static string waDemoUrl = ConfigurationManager.AppSettings["waDemoURL"];

        public static async Task<DemoData> GetDemoData(RequestAddress requestAddress)
        {
            try
            {
                using (var httpClient = new HttpClient() { MaxResponseContentBufferSize = 10000000, Timeout = TimeSpan.FromMilliseconds(5000) })
                {
                    string reasonPhrase = "";
                    var demoUri = new Uri(string.Format(waDemoUrl + "api/DemoApp/GetSomeData?trackingId={0}&clientKey={1}&address={2}", requestAddress.TrackingId, requestAddress.ClientKey, requestAddress.Address));

                    var httpResult = new HttpResponseMessage();
                    var result = RequestAccessToken.RequestToken().Result;
                    var accessToken = await Task.Run(() => RequestAccessToken.RequestToken().Result);
                    //var accessToken = RequestAccessToken.RequestToken().Result;
                    //which of the above two options should I use?  Does it matter?
                    httpClient.SetBearerToken(accessToken);
                    HttpResponseMessage response = await httpClient.GetAsync(demoUri);
                    HttpContent httpContent = response.Content;
                    if (httpResult.IsSuccessStatusCode)
                    {
                        var content = await httpContent.ReadAsStringAsync();
                        DemoData demoData = null;
                        demoData = JsonConvert.DeserializeObject<DemoData>(content);
                        return demoData;
                    }
                    else
                    {
                        reasonPhrase = httpResult.ReasonPhrase;
                        if (reasonPhrase.ToUpper() == "UNAUTHORIZED")
                        {
                            throw new KeyNotFoundException("Not authorized");
                        }
                    }
                }
            }
            catch (Exception ex)
            {
                Debug.WriteLine("Message is:" + ex);
                throw (ex);
            }
            return null;
        }
    }
}

And this is how the token is retrieved:

using Newtonsoft.Json;
using System;
using System.Collections.Generic;
using System.Configuration;
using System.Linq;
using System.Net;
using System.Net.Http;
using System.Threading;
using System.Threading.Tasks;
using System.Web;
using Thinktecture.IdentityModel.Tokens.Http;

namespace Demo.IdentityServer.IdentityModel.Client
{
    public static class RequestAccessToken
    {
        public readonly static string securityUrl = ConfigurationManager.AppSettings["securityUrl"];
        public readonly static string clientSecret = ConfigurationManager.AppSettings["clientSecret"];
        public static async Task<string> RequestToken()
        {

            var url = new Uri(securityUrl);

            var fields = new Dictionary<string, string>
            {
                { OAuth2Constants.GrantType, OAuth2Constants.GrantTypes.ClientCredentials },
                { OAuth2Constants.Scope, "Read"}
            };

            using (var httpClient = new HttpClient())
            {
                var cancellationToken = new CancellationToken();

                httpClient.DefaultRequestHeaders.Authorization = new BasicAuthenticationHeaderValue("Demo", clientSecret);

                var ss = JsonConvert.SerializeObject(fields);
                var data = new FormUrlEncodedContent(fields);
                var s = data.ReadAsStringAsync();

                //var response = await httpClient.PostAsync(url, data, cancellationToken).ConfigureAwait(false);
                var response = await httpClient.PostAsync(url, data, cancellationToken);
                // Should I use ConfigureAwait(false) or call method with a Task(Run() ... ?

                if (response.StatusCode == HttpStatusCode.OK || response.StatusCode == HttpStatusCode.BadRequest)
                {
                    //var content = await response.Content.ReadAsStringAsync().ConfigureAwait(false);
                    var content = await response.Content.ReadAsStringAsync();

                    var token = new TokenResponse(content);

                    var accessToken = token.AccessToken;

                    return accessToken;
                }
                else
                {
                    return new TokenResponse(response.StatusCode, response.ReasonPhrase).AccessToken;
                }
            }
        }
    }
}   
c#
owin
dotnet-httpclient
identityserver3
asked on Stack Overflow Jun 21, 2016 by user2197446 • edited May 18, 2017 by user2197446

2 Answers

3

SOLUTION Found!!! The entire issue stemmed from a misconfigured Load Balancer. Something with the SNAT pool. I'm not the network guy, and whatever he did fixed it. Something like the load balancer was referencing the box name directly instead of the SNAT Pool name, or the SNAT Pool had the wrong name. Either way once updated the intermittent successes became always successes.

answered on Stack Overflow May 18, 2017 by user2197446
0

I can tell you that you are flirting with SNAT port exhaustion at scale. It makes sense to instantiate HttpClient within a using block since it implements IDisposable. However, doing so will lead to HttpClient monopolizing one SNAT port for 240 seconds after it is disposed. See here for a great explanation of this problem.

answered on Stack Overflow Mar 19, 2020 by Rob Reagan

User contributions licensed under CC BY-SA 3.0