Enyim membase client inactivity disconnect issue
I am using the membase client from a windows service and it seems to be disconnecting after a period of inactivity. Is there any way I can force it to reconnect?
Think I got this fixed. Realized all I needed to do was make my instance variable for the cache static to keep it from getting GC'ed.
Never mind. fix did not work. Connection was lost anyway.
I don't think there's any reason the connection should be dropped either due to the client or the server. Do you have a simple example that shows the issue? Is it just create a client, then wait for a while and try to use it?
I turned on logging for the client. Here is the area where the problem started to occur:
2011-09-08 01:19:10 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Socket was reset. 0ac1d5c5-b8af-42ee-b056-61fac2d35d22
2011-09-08 01:19:10 [DEBUG] 8 Membase.VBucketAwareOperationFactory.VBStore - Key houapp03-a0f0a5f5-1a0f-4e3d-b18c-75bdb0bd9a48-datacache was mapped to 42
2011-09-08 01:19:10 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Releasing socket 0ac1d5c5-b8af-42ee-b056-61fac2d35d22
2011-09-08 01:19:10 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Are we alive? True
2011-09-08 01:50:48 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Acquiring stream from pool. 10.10.92.120:11210
2011-09-08 01:50:48 [DEBUG] 8 Enyim.Caching.Memcached.PooledSocket - Socket 0ac1d5c5-b8af-42ee-b056-61fac2d35d22 was reset
2011-09-08 01:50:48 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Socket was reset. 0ac1d5c5-b8af-42ee-b056-61fac2d35d22
2011-09-08 01:50:48 [DEBUG] 8 Membase.VBucketAwareOperationFactory.VBStore - Key houapp03-d36c3f2f-ef50-4bf1-acd0-5a4f1a5e425c-datacache was mapped to 510
2011-09-08 01:50:48 [ERROR] 8 Enyim.Caching.Memcached.MemcachedNode - System.IO.IOException: Failed to read from the socket '10.10.92.120:11210'. Error: ConnectionReset
at Enyim.Caching.Memcached.PooledSocket.BasicNetworkStream.Read(Byte[] buffer, Int32 offset, Int32 count) in d:\d\repo\EnyimMemcached\Enyim.Caching\Memcached\BasicNetworkStream.cs:line 92
at System.IO.BufferedStream.Read(Byte[] array, Int32 offset, Int32 count)
at Enyim.Caching.Memcached.PooledSocket.Read(Byte[] buffer, Int32 offset, Int32 count) in d:\d\repo\EnyimMemcached\Enyim.Caching\Memcached\PooledSocket.cs:line 221
at Enyim.Caching.Memcached.Protocol.Binary.BinaryResponse.Read(PooledSocket socket) in d:\d\repo\EnyimMemcached\Enyim.Caching\Memcached\Protocol\Binary\BinaryResponse.cs:line 57
at Enyim.Caching.Memcached.Protocol.Binary.BinarySingleItemOperation.ReadResponse(PooledSocket socket) in d:\d\repo\EnyimMemcached\Enyim.Caching\Memcached\Protocol\Binary\BinarySingleItemOperation.cs:line 22
at Enyim.Caching.Memcached.Protocol.Operation.Enyim.Caching.Memcached.IOperation.ReadResponse(PooledSocket socket) in d:\d\repo\EnyimMemcached\Enyim.Caching\Memcached\Protocol\Operation.cs:line 26
at Enyim.Caching.Memcached.MemcachedNode.ExecuteOperation(IOperation op) in d:\d\repo\EnyimMemcached\Enyim.Caching\Memcached\MemcachedNode.cs:line 474
2011-09-08 01:50:48 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Releasing socket 0ac1d5c5-b8af-42ee-b056-61fac2d35d22
2011-09-08 01:50:48 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Are we alive? True
2011-09-08 01:50:48 [WARN] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Marking node 10.10.92.120:11210 as dead
2011-09-08 01:50:48 [DEBUG] 8 Membase.MembasePool - Node 10.10.92.120:11210 is dead.
2011-09-08 01:50:48 [DEBUG] 8 Membase.MembasePool - We have a vbucket enabled bucket, skipping the timer.
2011-09-08 01:50:48 [DEBUG] 8 Membase.MembasePool - Fail handler is finished.
2011-09-08 01:50:52 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Acquiring stream from pool. 10.10.92.120:11210
2011-09-08 01:50:52 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Pool is dead or disposed, returning null. 10.10.92.120:11210
2011-09-08 01:51:39 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Acquiring stream from pool. 10.10.92.120:11210
2011-09-08 01:51:39 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Pool is dead or disposed, returning null. 10.10.92.120:11210
2011-09-08 01:51:43 [DEBUG] 8 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl - Acquiring stream from pool. 10.10.92.120:11210
Looking at that, the socket reset is almost exactly 30 minutes later. There's not, by chance, a stateful firewall or some kind of loadbalancer limiting connections to 30 minutes in there somewhere.
I'll check with some others, but I know we don't expect the socket to be reset from the server side. There must be something else going on here.
Actually that is a snippet of the entire log. There is no easily identifiable interval. However I got in touch with the Enyim developer and he has a fork that has a fix in it for this very issue.
What is happening is that the membase server and the client server are separated by a vpn tunnel, and every so often the network hiccups. (our network provider is having issues, and we are replacing them) When the hiccup occurs, the enyim client loses connectivity and then marks that node as dead.
I am working with him now to try to get his fix in place. It does not appear to be an issue with the membase server itself.
Ah, Attila was one of the folks I was going to check with. We work closely with him, as you may know. Glad to know there is a fix. We'll get that updated on the site as soon as there is a release.
I am using this client btw: https://github.com/downloads/enyim/EnyimMemcached/Membase.2.14.nupkg