Max pool size reached in 3.2.19

Legacy Uncategorised
#1

The following exceptions were found in our Octopus Deploy server this morning, no setting was specifically added to change the default max pool size which should be 100 (per https://msdn.microsoft.com/en-us/library/system.data.sqlclient.sqlconnection.connectionstring(v=vs.110).aspx) and I find it strange to imagine that it reached that limit. Maybe you guys have seen this before:

2016-02-01 19:33:40.1730 13 ERROR Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.
System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.
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.TryOpenInner(TaskCompletionSource1 retry) at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource1 retry)
at System.Data.SqlClient.SqlConnection.Open()
at Octopus.Shared.TransientFaultHandling.RetryPolicy.<>c__DisplayClass26_0.b__0() in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 172
at Octopus.Shared.TransientFaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 215 at Octopus.Core.RelationalStorage.RelationalStore.BeginTransaction(IsolationLevel isolationLevel, RetriableOperation retriableOperation) in Y:\work\refs\tags\3.2.19\source\Octopus.Core\RelationalStorage\RelationalStore.cs:line 63 at Octopus.Core.Model.Clustering.OctopusClusterService.UpdateLastSeen() in Y:\work\refs\tags\3.2.19\source\Octopus.Core\Model\Clustering\OctopusClusterService.cs:line 48 at Octopus.Core.Model.Clustering.OctopusClusterService.Heartbeat() in Y:\work\refs\tags\3.2.19\source\Octopus.Core\Model\Clustering\OctopusClusterService.cs:line 35 at Octopus.Server.Schedules.Scheduler.Heartbeat() in Y:\work\refs\tags\3.2.19\source\Octopus.Server\Schedules\Scheduler.cs:line 98 2016-02-01 19:33:40.2510 567 ERROR Unhandled exception from web server: An exception was thrown while executing a resolve operation. See the InnerException for details. ---> Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. (See inner exception for details.) Autofac.Core.DependencyResolutionException: An exception was thrown while executing a resolve operation. See the InnerException for details. ---> Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. (See inner exception for details.) ---> System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. 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.TryOpenInner(TaskCompletionSource1 retry)
at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource1 retry) at System.Data.SqlClient.SqlConnection.Open() at Octopus.Shared.TransientFaultHandling.RetryPolicy.<>c__DisplayClass26_0.<ExecuteAction>b__0() in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 172 at Octopus.Shared.TransientFaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 215
at Octopus.Core.RelationalStorage.RelationalStore.BeginTransaction(IsolationLevel isolationLevel, RetriableOperation retriableOperation) in Y:\work\refs\tags\3.2.19\source\Octopus.Core\RelationalStorage\RelationalStore.cs:line 63
at Autofac.Builder.RegistrationBuilder.<>c__DisplayClass11.<ForDelegate>b__0(IComponentContext c, IEnumerable1 p)
at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters)
at Autofac.Core.Lifetime.LifetimeScope.GetOrCreateAndShare(Guid id, Func1 creator) at Autofac.Core.Resolving.InstanceLookup.Execute() at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters)
at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Execute()
at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters) at Autofac.Core.Activators.Reflection.ConstructorParameterBinding.Instantiate() at Autofac.Core.Activators.Reflection.ReflectionActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Execute() at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters)
at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Execute()
at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters) at Autofac.Core.Resolving.ResolveOperation.Execute(IComponentRegistration registration, IEnumerable1 parameters)
— End of inner exception stack trace —
at Autofac.Core.Resolving.ResolveOperation.Execute(IComponentRegistration registration, IEnumerable1 parameters) at Autofac.ResolutionExtensions.ResolveService(IComponentContext context, Service service, IEnumerable1 parameters)
at Autofac.ResolutionExtensions.Resolve[TService](IComponentContext context, IEnumerable1 parameters) at Octopus.Server.Web.OctopusWebBootstrapper.RequestStartup(ILifetimeScope container2, IPipelines pipelines, NancyContext context) in Y:\work\refs\tags\3.2.19\source\Octopus.Server\Web\OctopusWebBootstrapper.cs:line 0 at Nancy.Bootstrapper.NancyBootstrapperWithRequestContainerBase1.InitializeRequestPipelines(NancyContext context)
at Nancy.NancyEngine.HandleRequest(Request request, Func2 preRequest, CancellationToken cancellationToken) at Nancy.NancyEngineExtensions.HandleRequest(INancyEngine nancyEngine, Request request, Func2 preRequest, Action1 onComplete, Action1 onError, CancellationToken cancellationToken)
at Octopus.Server.Web.OctopusNancyHost.Process(HttpListenerContext ctx) in Y:\work\refs\tags\3.2.19\source\Octopus.Server\Web\OctopusNancyHost.cs:line 447
2016-02-01 19:33:42.4542 370 ERROR Unhandled exception from web server: An exception was thrown while executing a resolve operation. See the InnerException for details. —> Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. (See inner exception for details.)
Autofac.Core.DependencyResolutionException: An exception was thrown while executing a resolve operation. See the InnerException for details. —> Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. (See inner exception for details.) —> System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.
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.TryOpenInner(TaskCompletionSource1 retry) at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource1 retry)
at System.Data.SqlClient.SqlConnection.Open()
at Octopus.Shared.TransientFaultHandling.RetryPolicy.<>c__DisplayClass26_0.b__0() in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 172
at Octopus.Shared.TransientFaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 215 at Octopus.Core.RelationalStorage.RelationalStore.BeginTransaction(IsolationLevel isolationLevel, RetriableOperation retriableOperation) in Y:\work\refs\tags\3.2.19\source\Octopus.Core\RelationalStorage\RelationalStore.cs:line 63 at Autofac.Builder.RegistrationBuilder.<>c__DisplayClass11.b__0(IComponentContext c, IEnumerable1 p) at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters) at Autofac.Core.Lifetime.LifetimeScope.GetOrCreateAndShare(Guid id, Func1 creator)
at Autofac.Core.Resolving.InstanceLookup.Execute()
at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters) at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Execute() at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters)
at Autofac.Core.Activators.Reflection.ConstructorParameterBinding.Instantiate()
at Autofac.Core.Activators.Reflection.ReflectionActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Execute()
at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters) at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Execute() at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters)
at Autofac.Core.Resolving.ResolveOperation.Execute(IComponentRegistration registration, IEnumerable1 parameters) --- End of inner exception stack trace --- at Autofac.Core.Resolving.ResolveOperation.Execute(IComponentRegistration registration, IEnumerable1 parameters)
at Autofac.ResolutionExtensions.ResolveService(IComponentContext context, Service service, IEnumerable1 parameters) at Autofac.ResolutionExtensions.Resolve[TService](IComponentContext context, IEnumerable1 parameters)
at Octopus.Server.Web.OctopusWebBootstrapper.RequestStartup(ILifetimeScope container2, IPipelines pipelines, NancyContext context) in Y:\work\refs\tags\3.2.19\source\Octopus.Server\Web\OctopusWebBootstrapper.cs:line 0
at Nancy.Bootstrapper.NancyBootstrapperWithRequestContainerBase1.InitializeRequestPipelines(NancyContext context) at Nancy.NancyEngine.HandleRequest(Request request, Func2 preRequest, CancellationToken cancellationToken)
at Nancy.NancyEngineExtensions.HandleRequest(INancyEngine nancyEngine, Request request, Func2 preRequest, Action1 onComplete, Action1 onError, CancellationToken cancellationToken) at Octopus.Server.Web.OctopusNancyHost.Process(HttpListenerContext ctx) in Y:\work\refs\tags\3.2.19\source\Octopus.Server\Web\OctopusNancyHost.cs:line 447 2016-02-01 19:33:43.9386 45 ERROR Unhandled exception from web server: An exception was thrown while executing a resolve operation. See the InnerException for details. ---> Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. (See inner exception for details.) Autofac.Core.DependencyResolutionException: An exception was thrown while executing a resolve operation. See the InnerException for details. ---> Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. (See inner exception for details.) ---> System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached. 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.TryOpenInner(TaskCompletionSource1 retry)
at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource1 retry) at System.Data.SqlClient.SqlConnection.Open() at Octopus.Shared.TransientFaultHandling.RetryPolicy.<>c__DisplayClass26_0.<ExecuteAction>b__0() in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 172 at Octopus.Shared.TransientFaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) in Y:\work\refs\tags\3.2.19\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 215
at Octopus.Core.RelationalStorage.RelationalStore.BeginTransaction(IsolationLevel isolationLevel, RetriableOperation retriableOperation) in Y:\work\refs\tags\3.2.19\source\Octopus.Core\RelationalStorage\RelationalStore.cs:line 63
at Autofac.Builder.RegistrationBuilder.<>c__DisplayClass11.<ForDelegate>b__0(IComponentContext c, IEnumerable1 p)
at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters)
at Autofac.Core.Lifetime.LifetimeScope.GetOrCreateAndShare(Guid id, Func1 creator) at Autofac.Core.Resolving.InstanceLookup.Execute() at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters)
at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Execute()
at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters) at Autofac.Core.Activators.Reflection.ConstructorParameterBinding.Instantiate() at Autofac.Core.Activators.Reflection.ReflectionActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Execute() at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters)
at Autofac.Core.Activators.Delegate.DelegateActivator.ActivateInstance(IComponentContext context, IEnumerable1 parameters) at Autofac.Core.Resolving.InstanceLookup.Activate(IEnumerable1 parameters)
at Autofac.Core.Resolving.InstanceLookup.Execute()
at Autofac.Core.Resolving.ResolveOperation.GetOrCreateInstance(ISharingLifetimeScope currentOperationScope, IComponentRegistration registration, IEnumerable1 parameters) at Autofac.Core.Resolving.ResolveOperation.Execute(IComponentRegistration registration, IEnumerable1 parameters)
— End of inner exception stack trace —
at Autofac.Core.Resolving.ResolveOperation.Execute(IComponentRegistration registration, IEnumerable1 parameters) at Autofac.ResolutionExtensions.ResolveService(IComponentContext context, Service service, IEnumerable1 parameters)
at Autofac.ResolutionExtensions.Resolve[TService](IComponentContext context, IEnumerable1 parameters) at Octopus.Server.Web.OctopusWebBootstrapper.RequestStartup(ILifetimeScope container2, IPipelines pipelines, NancyContext context) in Y:\work\refs\tags\3.2.19\source\Octopus.Server\Web\OctopusWebBootstrapper.cs:line 0 at Nancy.Bootstrapper.NancyBootstrapperWithRequestContainerBase1.InitializeRequestPipelines(NancyContext context)
at Nancy.NancyEngine.HandleRequest(Request request, Func2 preRequest, CancellationToken cancellationToken) at Nancy.NancyEngineExtensions.HandleRequest(INancyEngine nancyEngine, Request request, Func2 preRequest, Action1 onComplete, Action1 onError, CancellationToken cancellationToken)
at Octopus.Server.Web.OctopusNancyHost.Process(HttpListenerContext ctx) in Y:\work\refs\tags\3.2.19\source\Octopus.Server\Web\OctopusNancyHost.cs:line 447

#2

Hi,

Thanks for getting in touch and reporting this. We had a similar report last year and fixed a few areas that could have been problematic but this is the first report we’ve had since then. The first thing I’d suggest is to restart your Octopus server as this should fix the immediate issue.

That said, I’ve raised a Github issue to investigate the issue further. You can track it’s progress at the following URL.
https://github.com/OctopusDeploy/Issues/issues/2348

If you see this happen again, there are some diagnostics you could perform on the SQL Server that may help us determine the source: https://msdn.microsoft.com/en-us/library/aa175863(SQL.80).aspx

Thanks again!

Rob

#3

Hi Rob,

            Thanks for the prompt answer, to remediate this temporarily I included the Max Pool Size attribute in the connection string with a value of 200 and restarted Octopus Deploy.

            That obviously made it work again, but I will keep track of this issue and will make sure to report any new findings.

Roberto

#4

We had a similar issue yesterday and I was able to isolate to a singular event, Listening Tentacles that are not responding to the health check.

A set of 12 servers were turned off because they were being moved from one data center to another and were left active in Octopus Deploy. For some reason the repeated health checks against them failing were the only entries available in the logs.

This was noticeable only because we are using Splunk to index the logs and we setup an alert when the pool reached 150, for which I got more than 20 notifications at the same time this issues were occurring.

To resolve this temporarily I increased the maximum pool size to 1000, but I would like to lower that back to 200 or remove it altogether.

#5

Hi Roberto,

Thank you very much for following-up! I have added the detail to the github issue and this should help us isolate and fix the issue! :slight_smile:

Thanks again!

Rob

#7