Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool

abm_4780

Proget Version:
Docker: inedo/proget@sha256:9b4052ad9ef2084de107e853bc1ce548f0bc19105670884189252bf2e6409390
Container host: Amazon Linux 2 - 2CPU, 8GB

SQL Server Express 12.0 - 2CPU, 4GB. Average # client connections to database 35, CPU usage - very low, RAM usage about 2GB. SQL instance used only for proget

Hi,
I am fairly regularly getting the following exception
Source may be either web application or GET request to feed.

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.

URL: http://proget.css.rxweb-dev.com/nuget/Default/FindPackagesById()?id='Microsoft.AspNetCore.JsonPatch'&semVerLevel=2.0.0
Referrer: (not set)
User: (unknown)
User Agent: NuGet .NET Core MSBuild Task/4.9.4 (Microsoft Windows 10.0.14393 )
Stack trace: at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection (System.Data.Common.DbConnection owningConnection, System.Threading.Tasks.TaskCompletionSource`1[TResult] retry, System.Data.Common.DbConnectionOptions userOptions, System.Data.ProviderBase.DbConnectionInternal oldConnection, System.Data.ProviderBase.DbConnectionInternal& connection) [0x0024d] in <0864334e7e474248b37afca9b637daa9>:0
at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal (System.Data.Common.DbConnection outerConnection, System.Data.ProviderBase.DbConnectionFactory connectionFactory, System.Threading.Tasks.TaskCompletionSource`1[TResult] retry, System.Data.Common.DbConnectionOptions userOptions) [0x00036] in <0864334e7e474248b37afca9b637daa9>:0
at System.Data.ProviderBase.DbConnectionClosed.TryOpenConnection (System.Data.Common.DbConnection outerConnection, System.Data.ProviderBase.DbConnectionFactory connectionFactory, System.Threading.Tasks.TaskCompletionSource`1[TResult] retry, System.Data.Common.DbConnectionOptions userOptions) [0x00000] in <0864334e7e474248b37afca9b637daa9>:0
at System.Data.SqlClient.SqlConnection.TryOpen (System.Threading.Tasks.TaskCompletionSource`1[TResult] retry) [0x0005d] in <0864334e7e474248b37afca9b637daa9>:0
at System.Data.SqlClient.SqlConnection.Open () [0x0003b] in <0864334e7e474248b37afca9b637daa9>:0
at Inedo.Data.SqlServerDatabaseContext.CreateConnection () [0x0006c] in <ee7a5f9ece0745948bcfc1883d4013bb>:0
at Inedo.ProGet.Data.ProGetDatabaseContext+WrappedSqlContext.Inedo.ProGet.Data.ProGetDatabaseContext.IWrappedContext.CreateConnection () [0x00000] in <2dcfc00c227f477f87d98687618184f0>:0
at Inedo.ProGet.Data.ProGetDatabaseContext.CreateConnection () [0x00000] in <2dcfc00c227f477f87d98687618184f0>:0
at Inedo.Data.DatabaseContext.ExecuteInternal (System.String storedProcName, Inedo.Data.GenericDbParameter[] parameters) [0x00064] in <ee7a5f9ece0745948bcfc1883d4013bb>:0
at Inedo.Data.DatabaseContext+<>c__DisplayClass29_0`1[TRow].<EnumerateTable>b__0 () [0x00000] in <ee7a5f9ece0745948bcfc1883d4013bb>:0
at Inedo.Data.StrongDataReader+<Read>d__6`1[TRow].MoveNext () [0x0003e] in <ee7a5f9ece0745948bcfc1883d4013bb>:0
at System.Linq.Enumerable.TryGetFirst[TSource] (System.Collections.Generic.IEnumerable`1[T] source, System.Boolean& found) [0x00045] in <22384ee444974b39bb55b725de39c721>:0
at System.Linq.Enumerable.FirstOrDefault[TSource] (System.Collections.Generic.IEnumerable`1[T] source) [0x00000] in <22384ee444974b39bb55b725de39c721>:0
at Inedo.ProGet.Data.DB+Context.Feeds_GetFeed (System.Nullable`1[T] Feed_Id, System.String Feed_Name) [0x0003d] in <2dcfc00c227f477f87d98687618184f0>:0
at Inedo.ProGet.Data.DB.Feeds_GetFeed (System.Nullable`1[T] Feed_Id, System.String Feed_Name) [0x00006] in <2dcfc00c227f477f87d98687618184f0>:0
at Inedo.ProGet.Feeds.Feed.GetFeed (System.String feedName) [0x00008] in <2dcfc00c227f477f87d98687618184f0>:0
at Inedo.ProGet.WebApplication.FeedEndpoints.FeedEndpointHandler.GetHttpHandler (Inedo.Web.Handlers.GetHandlerParams args) [0x0015d] in <bc875334f36a4cd68d7eae7d4f0a0b2c>:0
at Inedo.Web.Handlers.DynamicHttpHandling.GetHandler (System.Web.HttpContext context, System.String requestType, System.String url, System.String pathTranslated) [0x0003b] in <552cf13df3c1427b87b305d8f051c033>:0
at Inedo.Web.InedoHttpModule.MapHandlerAndBeginRequestAsync (System.Web.HttpApplication app) [0x00029] in <552cf13df3c1427b87b305d8f051c033>:0
at Inedo.Web.InedoHttpModule.HandleBeginRequestInternalAsync (System.Web.HttpApplication app) [0x0000f] in <552cf13df3c1427b87b305d8f051c033>:0
at Inedo.Web.InedoHttpModule.ProcessBegin (System.Object sender, System.EventArgs e, System.AsyncCallback cb, System.Object extraData) [0x0000d] in <552cf13df3c1427b87b305d8f051c033>:0
at System.Web.HttpApplication+<RunHooks>d__217.MoveNext () [0x000a4] in <b4f0b153c02f4f0588d3f7549d75281b>:0
at System.Web.HttpApplication+<Pipeline>d__225.MoveNext () [0x0012c] in <b4f0b153c02f4f0588d3f7549d75281b>:0
at System.Web.HttpApplication.Tick () [0x00000] in <b4f0b153c02f4f0588d3f7549d75281b>:0

atripp

Hello; this is a sign of network connectivity being overloaded.

Ultimately your best bet is to use load balancing; see How to Prevent Server Overload in ProGet to learn more.

But I've heard that putting a NGIX reverse proxy in-front of the Linux container helps (due to some poor network handling/bugs by Mono's code) or moving to the Windows/IIS stack.

abm_4780

@atripp
Hi,
Do you have any links to people using nginx reverse-proxy setups?
We did have it running on Windows, but moved it to docker to simplify upgrades - i.e. less downtime.

Are there any plans in future for proget to become a native .net standard application and therefore not require mono?

atripp

We don't document how to set-up the ngix proxy, but it's a fairly common setup, and the way to support HTTPS on Linux.

Yes, our plan is to move to .NET5 as Microsoft comes closer to releasing that and it's proven stable (likely next year).

abm_4780

@atripp Good to know that netcore is in the pipeline.

Regarding using nginx, not exactly sure how this would help with Mono's network handling.
I have the containerised instance in AWS, and SSL offloading is being handled by an Elastic Load Balancer.
If I have nginx between the ELB and the proget container, surely it is just going to pass the connections straight through, unless it is configured to cache as well?

atripp

@abm_4780 said in Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool:

Regarding using nginx, not exactly sure how this would help with Mono's network handling.

I really don't remember the details, it was a while ago; it had something to do with keep-alive connections, perhaps? It made no sense, at all, but ngix fixed it. Later on, mono fixed whatever bug caused it.

abm_4780

@atripp
I shall try putting a proxy in front of it in due course.

"Later on, mono fixed whatever bug caused it."

Do you plan to release a version with the fixed mono libraries anytime soon?

Either way, thanks for your help so far.

atripp

The ProGet Dockerfile is based on mono, which is the latest stable version; so, every maintenance release it's whatever the latest version is at the time.

wsah_6160

We are experiencing the same issue @abm_4780 has experienced. We have the Proget container behind an AWS application load balancer and see the timeouts when one teamcity build agent(4vCPU and 8GB) requests the nuget packages. @abm_4780, did putting the container behind nginx solve your issue? Also worth noting that this looks like Proget is using all pooled data connections, and increasing max pool size does not seem to have an impact. Moving to Microsoft IIS stack did solve the problem but we were trying to avoid using a Windows server.

Thanks,
Adam

pluskal_4199

@wsah_6160 I have tried putting it behind nginx but the issue is still the same. For me, only one build agent with one build job overwhelms proget...

atripp

@wsah_6160 @pluskal_4199 assuming this is related to 5.3, then there should be a fix coming soon!