November Happy Hour will be moved to Thursday December 5th.

.NET 4 upgrade from .NET 3.5: Timeout period elapsed prior to obtaining a conneciton from the pool

Vote:
 

Hi all,

Help please! We've just gone through a massive upgrade process to move our website from VS2008 to VS2012 - i.e. .NET 3.5 to .NET 4.0. We're running a load-balanced environment - 2 web servers and use the EPi load-balancing with UDP.We use EPiServer CMS R2 and EPiServer Composer 4, as well as PageTypeBuilder


All seemed to be going smoothly,until we started getting the following errors recorded from one of our load balanced servers. The other server also seems to struggle, with CPU maxing out, but that server isn't reporting the same 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.

Symptoms on both servers seem to suggest that something is happening which is causing requests to queue up and the result manifests in the above errors. We also seem to get these errors almost as soon as we recycle the website app pool. However, at intermittent periods, we'll start getting these errors again, the site slows right down, and the site almost seems like its recycling - except it isn't - the worker process remains. 

It's almost as though EPiServer is reinitialising.

The database seems fine. We've increased the Max pools settings on the connection string to the EPi DB to 1000 (even though we had no need to do this in the .NET 3.5 site) and have also explicitly set Pooling=true, even though this is the default.

We've also checked through our code to make sure that any sql calls make use of the "using" statement, but really this seems unrelated because it seems to be EPiServer that's experiencing the problems and we don't make direct sql calls to EPi

We've enabled EPi logging, but haven't had an occurrence yet this morning to see it in action, but will post if that reveals anything.

(This seems simliar to the following post, but no one has responded to it http://world.episerver.com/Modules/Forum/Pages/Thread.aspx?id=11218&)

Please let us know if you have any suggestions!

Mazza

 

#79234
Dec 11, 2013 13:22
Vote:
 

What does the EPiServer log say when you start up? I know Page Type Builder can do a lot of activity against the database when starting up if you haven't set the sort order of the properties explicitly in your page type.

Frederik

#79237
Dec 11, 2013 13:42
Vote:
 

We haven't had to restart the website yet this morning (this is production) so haven't been able to witness the start-up. However, we have been having intermittent slow-downs where the CPU spikes. Also, by running the following stored proc, we see that the number of processes on the EPi DB increases:


SELECT  DB_NAME(dbid) as DBName, COUNT(dbid) as NumberOfProcesses, loginame as LoginName
FROM    sys.sysprocesses
WHERE dbid > 0 GROUP BY
    dbid, loginame

We've seen the number of processes for the EPi DB increase from 800 to over 2400 and then back down again. The w3wp process number hasn't changed all morning so we know it hasn't recycled. For the last couple of hours we've been running on just 1 of the load balanced servers. A few mins later the site is fine again, but haven't found a pattern to it yet.


During one of the periods of slow-down, I switched the EPi logging to INFO (very verbose so can only do that for a couple of mins). There were a lot of the following type of records (I have no idea if they have any bearing on this issue)

2013-12-11 13:54:54,848 INFO [155] ?.? - cacheKey=EP:LanguageBranch, retry 1, CacheManager.RuntimeCacheGet returned object of type EPiServer.DataAbstraction.LanguageBranchCollection[] for key
2013-12-11 13:54:54,849 INFO [155] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EP:LanguageBranch, retry 1, returning object of type TObject
2013-12-11 13:54:54,849 INFO [155] EPiServer.Core.OptimisticCache`1.Read - cacheKey=EP:LanguageBranch, returning an object of type TObject
2013-12-11 13:54:54,848 INFO [149] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EPPageData:45946, retry 1, returning object of type TObject
2013-12-11 13:54:54,849 INFO [149] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EPPageData:378
2013-12-11 13:54:54,849 INFO [149] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EPPageData:378, retry 1, calling CacheManager.RuntimeCacheGet for key
2013-12-11 13:54:54,849 INFO [149] ?.? - cacheKey=EPPageData:378, retry 1, CacheManager.RuntimeCacheGet returned object of type EPiServer.Core.PageData for key
2013-12-11 13:54:54,849 INFO [149] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EPPageData:378, retry 1, returning object of type TObject
2013-12-11 13:54:54,850 INFO [149] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EPPageData:21198
2013-12-11 13:54:54,849 INFO [155] EPiServer.Core.OptimisticCache`1.Read - cacheKey=EP:LanguageBranch
2013-12-11 13:54:54,850 INFO [155] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EP:LanguageBranch
2013-12-11 13:54:54,850 INFO [155] EPiServer.Core.OptimisticCache`1.TryRead - cacheKey=EP:LanguageBranch, retry 1, calling CacheManager.RuntimeCacheGet for key

As far as warnings, a few of these:

2013-12-11 13:55:54,835 WARN [PipeServerChannel.ServerMain] Microsoft.Samples.Runtime.Remoting.Channels.Pipe.PipeServerChannel.ServerMain - 18.3.1 Scheduler error:  Terminating client connection: Error reading from pipe 16420: error 109
2013-12-11 13:55:54,836 INFO [PipeServerChannel.ServerMain] Microsoft.Samples.Runtime.Remoting.Channels.Pipe.PipeServerChannel.ServerMain - 18.3.1 Scheduler info: PipeChannel.Dispose \\.\pipe\_LM_W3SVC_30_ROOT

Again, not sure if these would be related

 

 

#79250
Dec 11, 2013 16:25
Vote:
 

We seem to be able to reproduce the CPU spike by using EPiServer Composer -  e.g. just loading Composer Edit on Page for any Composer-enabled page within the editor.


We put the latest Windows patches on both servers. so they're both up to date, and we haven't seen the "Timeout period elapsed prior to obtaining a conneciton from the pool" error, but the effects are still hte same. CPU spikes and sys.sysprocesses count (from SQL statement described in previous post) increases to over 800. When not using Composer, sysprocesses count seems to remain at 800 for the EPi DB

#79260
Dec 11, 2013 21:10
This thread is locked and should be used for reference only. Please use the Episerver CMS 7 and earlier versions forum to open new discussions.
* You are NOT allowed to include any hyperlinks in the post because your account hasn't associated to your company. User profile should be updated.