Event log errors and IIS App Pool shutdown

Couchbase Server
1

Hi, I have a lot of repeating errors in the Event log viewer (windows) but can’t find anything on google about it.

After a while, the application pool stops because of too many errors.

This is the error :

Exception: System.TypeInitializationException Message: The type initializer for ‘Enyim.Caching.MemcachedClient’ threw an exception. StackTrace: at Enyim.Caching.MemcachedClient.Finalize() InnerException: System.Web.HttpException Message: An error occurred while attempting to impersonate. Execution of this request cannot continue.

I’m using a memcached bucket on a web farm (3 servers). I have to say that the site works and couchbase too. Wehn I go to the console, I can see all the requests users are making and it seems to work well. It’s just that the even viewer is full of errors and the application pool stops once in a while and this is the only reason I can find. If I can fix this memcached error I’m pretty sure it will fix everything.

The app is runned by IIS ApplicationPoolIdentity so it’s run by the application pool itself (IIS7).

This is what I use in my web.config.

I intentionaly removed the end of my ip adress.

What are the correct permissions I have to give to the impersonated security context. And to which user ? the application pool of my web app ?

I’m not calling client.Dispose(); anywhere. Where should it be called ? I use a static instance of the client as a singleton like this.

private static readonly CouchbaseClient _cacheInstance = new CouchbaseClient(“couchbase”);

internal static CouchbaseClient CacheInstance
{
get { return _cacheInstance; }
}

And when I need it I only call

MyClass.CacheInstance.Store(StoreMode.Set, storeID, objToStore);

NEW

I added Log4Net and this is what happen when the problem occurs :

2014-03-27 14:13:18,281 [74] WARN Couchbase.MessageStreamListener [(null)] <(null)> - HB: Node ‘http://172.16.127.27:8091/pools’ is OK
2014-03-27 14:13:28,281 [53] WARN Couchbase.MessageStreamListener [(null)] <(null)> - HB: Pinging current node ‘http://172.16.127.27:8091/pools’ to check if it’s still alive.
2014-03-27 14:13:28,281 [53] WARN Couchbase.MessageStreamListener [(null)] <(null)> - HB: Trying 'http://172.16.127.27:8091/pools’
2014-03-27 14:13:28,281 [53] WARN Couchbase.MessageStreamListener [(null)] <(null)> - HB: Node ‘http://172.16.127.27:8091/pools’ is OK
2014-03-27 14:13:31,437 [74] DEBUG Enyim.Caching.MemcachedClient [(null)] <(null)> - Disposing Couchbase.CouchbaseClient
2014-03-27 14:13:31,437 [74] DEBUG Enyim.Caching.MemcachedClient [(null)] <(null)> - Disposing Couchbase.CouchbaseClient
2014-03-27 14:13:31,437 [74] WARN Couchbase.CouchbasePool [(null)] <(null)> - Disposing Couchbase.CouchbasePool
2014-03-27 14:13:31,453 [74] WARN Couchbase.MessageStreamListener [(null)] <(null)> - Stopping the listener.
2014-03-27 14:13:31,453 [74] WARN Couchbase.MessageStreamListener [(null)] <(null)> - Stopped.
2014-03-27 14:13:31,453 [cbp_thread] WARN Couchbase.MessageStreamListener [(null)] <(null)> - ReadMessage failed with exception:
System.Net.WebException: The request was aborted: The request was canceled.
at System.Net.ConnectStream.Read(Byte[] buffer, Int32 offset, Int32 size)
at System.IO.StreamReader.ReadBuffer()
at System.IO.StreamReader.ReadLine()
at Couchbase.MessageStreamListener.ReadMessages(Uri heartBeatUrl, Uri configUrl)
at Couchbase.MessageStreamListener.ProcessPool()
2014-03-27 14:13:31,453 [cbp_thread] WARN Couchbase.MessageStreamListener [(null)] <(null)> - Reached the retry limit, rethrowing.
System.Net.WebException: The request was aborted: The request was canceled.
at System.Net.ConnectStream.Read(Byte[] buffer, Int32 offset, Int32 size)
at System.IO.StreamReader.ReadBuffer()
at System.IO.StreamReader.ReadLine()
at Couchbase.MessageStreamListener.ReadMessages(Uri heartBeatUrl, Uri configUrl)
at Couchbase.MessageStreamListener.ProcessPool()
2014-03-27 14:13:31,453 [74] WARN Couchbase.CouchbaseNode [(null)] <(null)> - Disposing Couchbase.CouchbaseNode - 172.16.127.27:11210
2014-03-27 14:13:31,453 [cbp_thread] WARN Couchbase.MessageStreamListener [(null)] <(null)> - Current node ‘http://172.16.127.27:8091/pools/default/bucketsStreaming/default?bucket_uuid=74739fb1cd9586da2dbf8549db314eed’ has failed.
2014-03-27 14:13:31,468 [74] WARN Couchbase.SocketPool [(null)] <(null)> - Disposing Couchbase.SocketPool on 172.16.127.27:11210 using thread:
2014-03-27 14:13:31,484 [74] INFO Couchbase.SocketPool [(null)] <(null)> - Gracefully closing 0453d2a3-d987-4994-8c33-739c839625ae on server 172.16.127.27:11210

2

It sounds like you are using impersonation to run that app under a security context other than default context? Perhaps as another windows user?

From the exception, it looks like impersonation fails when the client object is finalized (“Enyim.Caching.MemcachedClient.Finalize()”) - the finalizer would be called if the client was not gracefully disposed (by calling client.Dispose()) by that application using it. Perhaps you need to give impersonated security context the correct permissions to execute the finalize method?

Also, you may want to add code to ensure that you dispose of the client when the app pool is refreshed or in any case where the client is destroyed.

-Jeff

3

I am not sure exactly what permissions would be required, I am somewhat guessing based off the stacktrace provided. One thing you could do is:

a) Determine if your app is running under impersonation (you might have to look into the code – check this link: http://blogs.msdn.com/b/carloc/archive/2007/09/29/remember-to-undo-your-impersonation.aspx)
b) If it is using impersonation, check the security context that is being used for impersonation
c) Change the permissions or perhaps if possible don’t use impersonation

I wish I could help you more, but I don’t have a huge amount of operational IIS experience and this appears to be specific to your application. FWIW, the finalizer is probably being called when your app pool refreshes and the whole application (CB client instance, etc) is reclaimed – note that when the finalizer is called, TCP connections will be closed – this could cause security exceptions if the app is running under a security context that does not have the correct privileges.

You might want to investigate why the app-pool refreshes are happening. Also, check your windows logs as well – you may get more information than just that managed exception.

Oh, and for the dispose call you would want to do that in one of the global application events: Application_OnEnd should work…

Hopefully this helps,

Jeff

4

Also, if you can enable logging on the client and set it to something higher than DEBUG. If you use a file appender, you can create a log file and then send it to me and I’ll take a look at it.