Kestrelhttpserver: Dotnet process thread count keeps on increasing creating overload

Created on 3 Feb 2018  路  30Comments  路  Source: aspnet/KestrelHttpServer

We have an ASPNetCore Web API application running on a development server. And recently it started showing some timeouts whenever there are many people testing the application. Upon inspection we found that the process is using about 8 GB RAM and the timeouts occur when CPU usage is very high. We tried some profiling and found out that there is a large amount of objects under

10525    332590464 System.Collections.Generic.Dictionary`2+Entry[[System.Threading.IAsyncLocal, System.Private.CoreLib],[System.Object, System.Private.CoreLib]][]

This was taken from the dotnet instance when it hit 1.2 GB RAM usage. Only later did we notice the large amount of threads.
thread_issue

After debugging for a while, we also found that the same behavior is also present in the DEBUG mode running on over development machine. With every new request a new thread is created but the new thread is added on to a pile and never cleared. I am confused as to what could be the reason for this.

dotnet version: 2.1.4
IIS Version: 8.5.9600.16384

picture sabeersulaiman
👍1

Most helpful comment

@benaadams Found out the issue, it was in a middleware in our own code, which was requesting for a log file which was already locked for writing I believe. Now everything is working fine. Thanks for the heads up.

picture sabeersulaiman on 5 Feb 2018
👍2 ❤1

All 30 comments

Could you install the https://github.com/benaadams/Ben.BlockingDetector (on NuGet) and see if it outputs anything to extra to your log on your development machine?

using Ben.Diagnostics;

public class Startup
{
    public void Configure(IApplicationBuilder app, ...)
    {
        // Add blocking detector at start of Configure
        app.UseBlockingDetection();
benaadams picture benaadams on 3 Feb 2018

@benaadams I got this bit.

Ben.Diagnostics.BlockingMonitor:Warning: Blocking method has been invoked and blocked, this can lead to threadpool starvation.
   at System.Threading.WaitHandle.WaitAny(WaitHandle[] waitHandles, Int32 millisecondsTimeout, Boolean exitContext)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.OpenAsync(CancellationToken cancellationToken)
   at Dapper.SqlMapper.<QueryAsync>d__31`1.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
   at Dapper.SqlMapper.QueryAsync[T](IDbConnection cnn, Type effectiveType, CommandDefinition command)
   at Dapper.SqlMapper.QueryAsync[T](IDbConnection cnn, String sql, Object param, IDbTransaction transaction, Nullable`1 commandTimeout, Nullable`1 commandType)
   at AdDin.Accounts.Repositories.UserIdentityRepository.<GetUserIdentityByUserName>d__2.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Accounts.Repositories.UserIdentityRepository.GetUserIdentityByUserName(String userName)
   at AdDin.Accounts.Services.UserNameAuthenticator.<VerifyIdentity>d__8.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Accounts.Services.UserNameAuthenticator.VerifyIdentity(UserIdentity identity)
   at AdDin.Accounts.Services.AdDinAuthenticator.<LoginWithAuth>d__6.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Accounts.Services.AdDinAuthenticator.LoginWithAuth(PasswordAuthModel model)
   at AdDin.Accounts.Controllers.AccountController.<Login>d__8.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Accounts.Controllers.AccountController.Login(PasswordAuthModel model)
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionMethodAsync>d__12.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAsync>d__10.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAwaitedAsync>d__11.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAwaitedAsync()
   at Microsoft.AspNetCore.Mvc.Filters.ActionFilterAttribute.<OnActionExecutionAsync>d__6.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Filters.ActionFilterAttribute.OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAsync>d__10.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAsync>d__10.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAwaitedAsync>d__11.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAwaitedAsync()
   at Microsoft.AspNetCore.Mvc.Controller.<OnActionExecutionAsync>d__27.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Controller.OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionFilter.<OnActionExecutionAsync>d__4.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionFilter.OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeInnerFilterAsync>d__14.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeInnerFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.<InvokeNextResourceFilter>d__22.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.<InvokeFilterPipelineAsync>d__17.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.<InvokeAsync>d__15.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()
   at Microsoft.AspNetCore.Mvc.Internal.MvcAttributeRouteHandler.<>c__DisplayClass12_0.<RouteAsync>b__0(HttpContext c)
   at Microsoft.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Builder.Extensions.MapMiddleware.<Invoke>d__3.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Builder.Extensions.MapMiddleware.Invoke(HttpContext context)
   at AdDin.Accounts.MiddleWares.APIAuthorizationMiddleware.<Invoke>d__3.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Accounts.MiddleWares.APIAuthorizationMiddleware.Invoke(HttpContext context)
   at AdDin.Accounts.MiddleWares.LinkedInOAuthMiddleware.<Invoke>d__2.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Accounts.MiddleWares.LinkedInOAuthMiddleware.Invoke(HttpContext context)
   at AdDin.Configuration.MiddleWares.LoggerMiddleWare.<Invoke>d__3.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Configuration.MiddleWares.LoggerMiddleWare.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.<Invoke>d__7.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.StaticFiles.DefaultFilesMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Builder.UseExtensions.<>c__DisplayClass0_2.<Use>b__2()
   at AdDin.Web.Startup.<>c.<<Configure>b__5_1>d.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Web.Startup.<>c.<Configure>b__5_1(HttpContext context, Func`1 next)
   at Microsoft.AspNetCore.Builder.UseExtensions.<>c__DisplayClass0_1.<Use>b__1(HttpContext context)
   at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.<Invoke>d__7.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.Invoke(HttpContext context)
   at Ben.Diagnostics.BlockingDetectionMiddleware.<Invoke>d__6.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Ben.Diagnostics.BlockingDetectionMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Server.IISIntegration.IISMiddleware.<Invoke>d__11.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Server.IISIntegration.IISMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.HttpOverrides.ForwardedHeadersMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.<Invoke>d__3.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Hosting.Internal.HostingApplication.ProcessRequestAsync(Context context)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame`1.<ProcessRequestsAsync>d__2.MoveNext()
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.<>c__DisplayClass4_0.<OutputAsyncCausalityEvents>b__0()
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.<>c.<.cctor>b__67_3(Object o)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.LoggingThreadPool.<>c__DisplayClass6_0.<Schedule>b__0()
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.LoggingThreadPool.<RunAction>b__3_0(Object o)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
sabeersulaiman picture sabeersulaiman on 3 Feb 2018

Using dapper for SQL database. Anything to do with this ? https://github.com/dotnet/corefx/issues/26348

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

That potentially, also DNS lookup for a SQL server blocks multiple times during connect. That has been fixed (sort of) for 2.1. The SQL provider is "interesting" to say the least.

Drawaes picture Drawaes on 3 Feb 2018

K that should be infrequent, its just setting up a pooled connection (it should do better; but unlikely the cause)

benaadams picture benaadams on 3 Feb 2018

Whenever I am sending a request to the Web API I am getting this output.

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

Another option is after you have many threads; to check Parallel Stacks Window in VS and see where the threads are stuck at and see if its a common place

benaadams picture benaadams on 3 Feb 2018

Whenever I am sending a request to the Web API I am getting this output.

It should only do it for the first few connections; then start to reuse the connections?

Unless your queries are taking really long

benaadams picture benaadams on 3 Feb 2018

Went to do this for a while on debug mode now the process is at 150+ threads I send about 50-60 requests, still getting the same output.

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

Does Parallel Stacks show you anything; as they might be blocked somewhere else

benaadams picture benaadams on 3 Feb 2018

I am not sure, first time using parellel stacks. Can't seem to pinpoint anything. I am looking into it.

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

Got a lot of threads showing this
parallel

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

The moment the api returns, the worker thread returns too I believe. But there are still a lot of threads.

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

If you change the drop down that says Threads to Tasks does it show anything more enlightening?

benaadams picture benaadams on 3 Feb 2018

Everything except for two is in Blocked status.

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

Blocked - The task is currently blocked in a wait state.

Are there lots and are they blocked in same place? You'll probably need to go up the call stack a little as they will be at Task.Wait or something like that.

benaadams picture benaadams on 3 Feb 2018

Blocked at [external code] all of them
block

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

Is there any way to know exactly which external code causes this ? Got something new in the output though

Ben.Diagnostics.BlockingMonitor:Warning: Blocking method has been invoked and blocked, this can lead to threadpool starvation.
   at System.Threading.TimerQueueTimer.Change(UInt32 dueTime, UInt32 period)
   at System.Threading.Timer.TimerSetup(TimerCallback callback, Object state, UInt32 dueTime, UInt32 period)
   at System.Threading.Timer..ctor(TimerCallback callback, Object state, TimeSpan dueTime, TimeSpan period)
   at Serilog.Sinks.File.PeriodicFlushToDiskSink..ctor(ILogEventSink sink, TimeSpan flushInterval)
   at Serilog.RollingFileLoggerConfigurationExtensions.RollingFile(LoggerSinkConfiguration sinkConfiguration, ITextFormatter formatter, String pathFormat, LogEventLevel restrictedToMinimumLevel, Nullable`1 fileSizeLimitBytes, Nullable`1 retainedFileCountLimit, LoggingLevelSwitch levelSwitch, Boolean buffered, Boolean shared, Nullable`1 flushToDiskInterval)
   at Microsoft.Extensions.Logging.FileLoggerExtensions.<>c__DisplayClass4_0.<CreateLogger>b__0(LoggerSinkConfiguration w)
   at Serilog.LoggerConfigurationAsyncExtensions.Async(LoggerSinkConfiguration loggerSinkConfiguration, Action`1 configure, Int32 bufferSize)
   at Microsoft.Extensions.Logging.FileLoggerExtensions.CreateLogger(String pathFormat, LogLevel minimumLevel, IDictionary`2 levelOverrides, Boolean isJson, Nullable`1 fileSizeLimitBytes, Nullable`1 retainedFileCountLimit)
   at Microsoft.Extensions.Logging.FileLoggerExtensions.AddFile(ILoggerFactory loggerFactory, String pathFormat, LogLevel minimumLevel, IDictionary`2 levelOverrides, Boolean isJson, Nullable`1 fileSizeLimitBytes, Nullable`1 retainedFileCountLimit)
   at AdDin.Configuration.MiddleWares.LoggerMiddleWare.<Invoke>d__3.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Configuration.MiddleWares.LoggerMiddleWare.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.<Invoke>d__7.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.StaticFiles.DefaultFilesMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Builder.UseExtensions.<>c__DisplayClass0_2.<Use>b__2()
   at AdDin.Web.Startup.<>c.<<Configure>b__5_1>d.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at AdDin.Web.Startup.<>c.<Configure>b__5_1(HttpContext context, Func`1 next)
   at Microsoft.AspNetCore.Builder.UseExtensions.<>c__DisplayClass0_1.<Use>b__1(HttpContext context)
   at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.<Invoke>d__7.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.Invoke(HttpContext context)
   at Ben.Diagnostics.BlockingDetectionMiddleware.<Invoke>d__6.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Ben.Diagnostics.BlockingDetectionMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Server.IISIntegration.IISMiddleware.<Invoke>d__11.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Server.IISIntegration.IISMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.HttpOverrides.ForwardedHeadersMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.<Invoke>d__3.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Hosting.Internal.HostingApplication.ProcessRequestAsync(Context context)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame`1.<ProcessRequestsAsync>d__2.MoveNext()
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.<>c__DisplayClass4_0.<OutputAsyncCausalityEvents>b__0()
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.<>c.<.cctor>b__67_3(Object o)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.LoggingThreadPool.<>c__DisplayClass6_0.<Schedule>b__0()
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.LoggingThreadPool.<RunAction>b__3_0(Object o)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
sabeersulaiman picture sabeersulaiman on 3 Feb 2018

The external code will be the Waiting at OS level, need to find out where it was before...

Did you attach to process or start in VS? (I think starting in VS gives more info)

Will see if I can improve the blocking detector to catch more cases, and you are using version 0.0.2 rather than 0.0.1?

benaadams picture benaadams on 3 Feb 2018

I am using v 0.0.2, I started the project from VS itself. Let me see if I can find the code before the blocking call.

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

It could be that its having trouble connecting to the database and its stuck waiting to timeout; so it might actually be creating that many connections and then getting stuck waiting for them

benaadams picture benaadams on 3 Feb 2018

Can reviewing the way we connect to the database help? My queries are working. But I do feel like something fishy is going on there. The same issue is happening on the server and our own devices. I will try debugging those areas.

sabeersulaiman picture sabeersulaiman on 3 Feb 2018

Question, are you using a localhost database? If so does using 127.0.0.1 rather than localhost help? https://github.com/dotnet/corefx/issues/24104

benaadams picture benaadams on 3 Feb 2018

My connection string is using system names instead of url, both on the server and dev machines.

sabeersulaiman picture sabeersulaiman on 4 Feb 2018

K, was wondering if you were hitting the issue where the address/hostname resolves on IPv6 (as well as IPv4); but the service (SqlServer in this case) is only accessible via IPv4 (firewall or just not listening) - causing an extra second+ to connect as it tries the IPv6 address first, waits for it to timeout, then tries to access it via IPv4.

Once you are connected there would be no delays, so all the queries would be normal speed

benaadams picture benaadams on 4 Feb 2018

@benaadams Found out the issue, it was in a middleware in our own code, which was requesting for a log file which was already locked for writing I believe. Now everything is working fine. Thanks for the heads up.

sabeersulaiman picture sabeersulaiman on 5 Feb 2018
👍2 ❤1

hi there , did you using nlog ?

SaliBatman picture SaliBatman on 17 Aug 2018

@SaliBatman No we were using Serilog, but afterwards we moved to NLog.

sabeersulaiman picture sabeersulaiman on 17 Aug 2018

@benaadams now wondering you were saying about IPV4 and V6 because we sometimes have this issue
when there is a huge load on our server. Not sure if its related. Could you help?
Unable to get the address of the distributed transaction coordinator for the server, from the server. Is DTC enabled on the server?

Stack trace
System.InvalidOperationException: Unable to get the address of the distributed transaction coordinator for the server, from the server. Is DTC enabled on the server?
at System.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)
at System.Data.ProviderBase.DbConnectionPool.PrepareConnection(DbConnection owningObject, DbConnectionInternal obj, Transaction transaction)
at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
at System.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection) at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource1 retry, DbConnectionOptions userOptions) at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource1 retry)
at System.Data.SqlClient.SqlConnection.OpenAsync(CancellationToken cancellationToken)
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.d__48.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.d__45.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable1.AsyncEnumerator.<BufferlessMoveNext>d__12.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.<ExecuteAsync>d__72.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable1.AsyncEnumerator.<MoveNext>d__11.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Linq.AsyncEnumerable.<SingleOrDefault_>d__3811.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.TaskResultAsyncEnumerable1.Enumerator.<MoveNext>d__3.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.ExceptionInterceptor1.EnumeratorExceptionInterceptor.d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.d__211.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Snappet.Metrics.DataAccess.Shared.QueryExtensions.<ExecuteAsync>d__61.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Snappet.Metrics.DataAccess.Shared.QueryExtensions.d__21.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Snappet.Metrics.Services.Cluster.LearningObjectiveService.<GetNumberOfStarsForLearningObjective>d__3.MoveNext() in E:\BuildAgent\work\60ef918917e4b555\src\Snappet.Metrics.Services.Cluster\LearningObjectiveService.cs:line 43 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Snappet.Metrics.Api.Controllers.V2.LearningObjectivesController.<>c__DisplayClass3_1.<<GetNumberOfStarsForLearningObjective>b__0>d.MoveNext() in E:\BuildAgent\work\60ef918917e4b555\src\Snappet.Metrics.Api\Controllers\V2\LearningObjectivesController.cs:line 38 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Snappet.Common.CancellableTaskRunner.<ExecuteCancellableFunction>d__01.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Snappet.Metrics.Api.Controllers.V2.LearningObjectivesController.d__3.MoveNext() in E:BuildAgentwork60ef918917e4b555srcSnappet.Metrics.ApiControllersV2LearningObjectivesController.cs:line 36
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor.TaskOfIActionResultExecutor.d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.d__10.MoveNext()

dharmenbavaria picture dharmenbavaria on 3 Dec 2018

@dharmenbavaria looks to be an issue originating with SqlClient; I'd suggest opening an issue in corefx about it: https://github.com/dotnet/corefx/issues

benaadams picture benaadams on 3 Dec 2018
Was this page helpful?
0 / 5 - 0 ratings

Related issues

NinoFloris picture NinoFloris  路  8Comments
ciriarte picture ciriarte  路  7Comments
Eilon picture Eilon  路  7Comments
felschr picture felschr  路  6Comments
fabiobraganet picture fabiobraganet  路  7Comments