Wrong magic value exception #94

Closed
vchekan opened this Issue Jan 11, 2012 · 4 comments

Comments

Projects
None yet
4 participants
@vchekan

vchekan commented Jan 11, 2012

Sometimes we see an error: "Expected magic value 129, received:". I have to open a new ticket instead of reopening the old one: #66.

The cause of this error is the following scenario:

  • Large data is receiving from memcached server (~1Mb)
  • While data reading is not complete yet, an exception happen (for examlple, ThreadAbortException is normal thing in Web based applications)
  • As long as exception is not IOException, PooledSocket is not marked as IsAlive=false and is returned into pool with dirty buffer
  • When this socket is reused, it is Reset and as many as Avialibe bytes are read and discard from the socket buffer. But if socket is reused quickly enough, due to network latencies and large data size (1Mb value), data may still be coming into even after Reset call. So there is no way to guarantee that Reset will really clean up buffer because we do not know when data will stop coming in
  • Data which keeps coming from previous request are read as a header and magic value corruption is detected.

The fix is here:
https://github.com/vchekan/EnyimMemcached/commit/cb44bdf61066f812bc2257d1aaf6d2c879fa9ec2
and it introduces a new state for PooledSoket: recoverable error. It means that socket itself is messed up and should be disposed, but server is fine and there is no need to mark server as dead.
Another change is that now any exception will lead to server "dead" state, not just IOException.

@reustmd

This comment has been minimized.

Show comment
Hide comment
@reustmd

reustmd Mar 13, 2012

What version did this get into? Has it been released to nuget? @vchekan

reustmd commented Mar 13, 2012

What version did this get into? Has it been released to nuget? @vchekan

@vchekan

This comment has been minimized.

Show comment
Hide comment
@vchekan

vchekan Mar 13, 2012

@reustmd I haven't heard from official maintainers yet, try to bug @enyim.

vchekan commented Mar 13, 2012

@reustmd I haven't heard from official maintainers yet, try to bug @enyim.

@givan

This comment has been minimized.

Show comment
Hide comment
@givan

givan May 2, 2013

Hello,

We're using the 2.12 version. We're storing about 10k of data (far less than the 1mb you mention above). What could be the reason?

[2013-05-02 00:00:00.212Z] Level=Error Component=AssetChangeManagement/1 Operation=GenerateAssetChanges TimeElapsed=10612.412 Service=AssetChangeManagement CoordinationId=AssetSyncNotification3e0cca2f-5d82-45cb-8ca8-cf699c6af1a2 SystemId=1110 CallerSystemId=1110 UserId=5990461 ErrorCount=1 ErrorCodes=SystemError ErrorMessages="Unknown error." WarningCount=0 Exception="System.InvalidOperationException: Expected magic value 129, received: 69
at Enyim.Caching.Memcached.Protocol.Binary.BinaryResponse.DeserializeHeader(Byte[] header, Int32& dataLength, Int32& extraLength)
at Enyim.Caching.Memcached.Protocol.Binary.BinaryResponse.Read(PooledSocket socket)
at Enyim.Caching.Memcached.Protocol.Binary.BinarySingleItemOperation.ReadResponse(PooledSocket socket)
at Enyim.Caching.Memcached.MemcachedNode.ExecuteOperation(IOperation op)
at Enyim.Caching.Memcached.MemcachedNode.Enyim.Caching.Memcached.IMemcachedNode.Execute(IOperation op)
at Enyim.Caching.MemcachedClient.PerformStore(StoreMode mode, String key, Object value, UInt32 expires, UInt64& cas, Int32& statusCode)
at GettyImages.MemCached.Enyim.MemcachedEnyimProvider.SetItem(IStateFilter filter, Object item, Int32 cacheTimeout)
at GettyImages.Frameworks.StateManager.StateManager.GetData[TData,TFilter](TFilter filter, ICacheProvider cacheProvider, GetDataDelegate2 getData, Int32 cacheTimeout) at GettyImages.Frameworks.StateManager.StateManager.GetData[TData,TFilter](String name, TFilter filter, GetDataDelegate2 getData)
at GettyImages.Services.AssetChangeManagement.Impl.Operations.GenerateAssetChangesOperation.Execute(Request request)
at GettyImages.Services.AssetChangeManagement.V1.GenerateAssetChanges.GenerateAssetChangesBridge.Execute(GenerateAssetChangesRequestMessage request, GenerateAssetChangesResponseMessage response)
at GettyImages.Services.Core.MessageRouter.RouteMessage[TRequest,TResponse](TRequest request)
at SyncInvokeGenerateAssetChanges(Object , Object[] , Object[] )
at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
at GettyImages.Services.Core.v2.Pipeline.HandleFatalExceptionsInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)" Request={"RequestBody":null,"Header":{"Token":"KfAuHwCMwVPblwp8fy926IWfsdXg//hADwDsOm/5ullzMS3nmFUOCNaM8Cap6x7fSLSvNtTKmp2Ox7siecaSbAvNwhLzM+dLAV4oHwjHXibjSrrK4cYGZ/wLcAJnzuPHBtZLIMOf3pRscK5agmYUzVqlRfcAxKJy/Vw3lyIiRAM=|77u/U2IzaXJqd2poM25JdEFsNmhkNHgKMTExMAo1OTkwNDYxCkFENWpCQT09CkNFVmpCQT09CjAKCgowCgoK|3","Detail":null,"CoordinationId":"AssetSyncNotification3e0cca2f-5d82-45cb-8ca8-cf699c6af1a2"}}

givan commented May 2, 2013

Hello,

We're using the 2.12 version. We're storing about 10k of data (far less than the 1mb you mention above). What could be the reason?

[2013-05-02 00:00:00.212Z] Level=Error Component=AssetChangeManagement/1 Operation=GenerateAssetChanges TimeElapsed=10612.412 Service=AssetChangeManagement CoordinationId=AssetSyncNotification3e0cca2f-5d82-45cb-8ca8-cf699c6af1a2 SystemId=1110 CallerSystemId=1110 UserId=5990461 ErrorCount=1 ErrorCodes=SystemError ErrorMessages="Unknown error." WarningCount=0 Exception="System.InvalidOperationException: Expected magic value 129, received: 69
at Enyim.Caching.Memcached.Protocol.Binary.BinaryResponse.DeserializeHeader(Byte[] header, Int32& dataLength, Int32& extraLength)
at Enyim.Caching.Memcached.Protocol.Binary.BinaryResponse.Read(PooledSocket socket)
at Enyim.Caching.Memcached.Protocol.Binary.BinarySingleItemOperation.ReadResponse(PooledSocket socket)
at Enyim.Caching.Memcached.MemcachedNode.ExecuteOperation(IOperation op)
at Enyim.Caching.Memcached.MemcachedNode.Enyim.Caching.Memcached.IMemcachedNode.Execute(IOperation op)
at Enyim.Caching.MemcachedClient.PerformStore(StoreMode mode, String key, Object value, UInt32 expires, UInt64& cas, Int32& statusCode)
at GettyImages.MemCached.Enyim.MemcachedEnyimProvider.SetItem(IStateFilter filter, Object item, Int32 cacheTimeout)
at GettyImages.Frameworks.StateManager.StateManager.GetData[TData,TFilter](TFilter filter, ICacheProvider cacheProvider, GetDataDelegate2 getData, Int32 cacheTimeout) at GettyImages.Frameworks.StateManager.StateManager.GetData[TData,TFilter](String name, TFilter filter, GetDataDelegate2 getData)
at GettyImages.Services.AssetChangeManagement.Impl.Operations.GenerateAssetChangesOperation.Execute(Request request)
at GettyImages.Services.AssetChangeManagement.V1.GenerateAssetChanges.GenerateAssetChangesBridge.Execute(GenerateAssetChangesRequestMessage request, GenerateAssetChangesResponseMessage response)
at GettyImages.Services.Core.MessageRouter.RouteMessage[TRequest,TResponse](TRequest request)
at SyncInvokeGenerateAssetChanges(Object , Object[] , Object[] )
at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
at GettyImages.Services.Core.v2.Pipeline.HandleFatalExceptionsInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)" Request={"RequestBody":null,"Header":{"Token":"KfAuHwCMwVPblwp8fy926IWfsdXg//hADwDsOm/5ullzMS3nmFUOCNaM8Cap6x7fSLSvNtTKmp2Ox7siecaSbAvNwhLzM+dLAV4oHwjHXibjSrrK4cYGZ/wLcAJnzuPHBtZLIMOf3pRscK5agmYUzVqlRfcAxKJy/Vw3lyIiRAM=|77u/U2IzaXJqd2poM25JdEFsNmhkNHgKMTExMAo1OTkwNDYxCkFENWpCQT09CkNFVmpCQT09CjAKCgowCgoK|3","Detail":null,"CoordinationId":"AssetSyncNotification3e0cca2f-5d82-45cb-8ca8-cf699c6af1a2"}}

@givan

This comment has been minimized.

Show comment
Hide comment
@givan

givan May 2, 2013

We found the problem. It turned out that our memcache server was outdated. Once we upgraded to memcached-1.4.4-3.el6.x86_64, we're able to store values using the version 2.12 driver.

givan commented May 2, 2013

We found the problem. It turned out that our memcache server was outdated. Once we upgraded to memcached-1.4.4-3.el6.x86_64, we're able to store values using the version 2.12 driver.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment