roc230 / spymemcached

Automatically exported from code.google.com/p/spymemcached
0 stars 0 forks source link

Timed out waiting for operation #83

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
What version of the product are you using? On what operating system?

Using spymemcached Version 2.3.1 on 
java version "1.6.0_07"
Java(TM) SE Runtime Environment (build 1.6.0_07-b06)
Java HotSpot(TM) 64-Bit Server VM (build 10.0-b23, mixed mode)

2009-08-07 01:35:48,332 ERROR TP-Processor151 ...
java.lang.RuntimeException: Timed out waiting for operation
        at net.spy.memcached.MemcachedClient$OperationFuture.get(MemcachedClient.java:1648)
        at com.clickbank.orders.OrderUtilities.storeMemCacheValue(OrderUtilities.java:328)
        at com.clickbank.orders.OrderUtilities.storeOrderInCache(OrderUtilities.java:204)

Then around 15 minutes later...
2009-08-07 01:51:50,844 INFO Memcached IO over {MemcachedConnection to 
/10.1.16.32:11211 /10.21.2.32:11211} net.spy.memcached.MemcachedConnection - 
Reconnecting due to exception on {QA sa=/10.21.2.32:11211, #Rops=1, #Wops=0, 
#iq=0, 
topRop=net.spy.memcached.protocol.ascii.StoreOperationImpl@419eeaa2, 
topWop=null, 
toWrite=0, interested=1}
java.io.IOException: Connection timed out
        at sun.nio.ch.FileDispatcher.read0(Native Method)
        at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
        at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
        at sun.nio.ch.IOUtil.read(IOUtil.java:206)
        at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
        at 
net.spy.memcached.MemcachedConnection.handleReads(MemcachedConnection.java:349)
        at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:305)
        at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:192)
        at net.spy.memcached.MemcachedClient.run(MemcachedClient.java:1444)
2009-08-07 01:51:50,844 WARN Memcached IO over {MemcachedConnection to 
/10.1.16.32:11211 /10.21.2.32:11211} net.spy.memcached.MemcachedConnection - 
Closing, 
and reopening {QA sa=/10.21.2.32:11211, #Rops=1, #Wops=0, #iq=0, 
topRop=net.spy.memcached.protocol.ascii.StoreOperationImpl@419eeaa2, 
topWop=null, 
toWrite=0, interested=1}, attempt 0.
2009-08-07 01:51:50,844 WARN Memcached IO over {MemcachedConnection to 
/10.1.16.32:11211 /10.21.2.32:11211} 
net.spy.memcached.protocol.ascii.AsciiMemcachedNodeImpl - Discarding partially 
completed 
op: net.spy.memcached.protocol.ascii.StoreOperationImpl@419eeaa2
2009-08-07 01:51:50,947 INFO Memcached IO over {MemcachedConnection to 
/10.1.16.32:11211 /10.21.2.32:11211} net.spy.memcached.MemcachedConnection - 
Reconnecting {QA sa=/10.21.2.32:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, 
topWop=null, toWrite=0, interested=0}
2009-08-07 01:51:50,979 INFO Memcached IO over {MemcachedConnection to 
/10.1.16.32:11211 /10.21.2.32:11211} net.spy.memcached.MemcachedConnection - 
Connection state changed for sun.nio.ch.SelectionKeyImpl@6db4e9d9

We were noticing many many Timed out errors when running little traffic across 
4 or 5 client 
servers.  I noticed that with little load across numerous clients we were 
waiting a few hours 
between operations on each client, and that's when the exceptions started to 
occur.  I made a 
change to store more items into memcache so that every client is busy all of 
the time, and the 
exceptions have completely stopped.

From the stacks listed above it seems that after a period of total client 
inactivity (seems like 60 
to 90 minutes or more is required), we will get a few Timed out stacks; and 
then it takes around 
15 minutes for the spymemcached client to recognize the damaged connection and 
reconnect.  
After the reconnect things are good until a few hours of inactivity occurs 
again.

-John

Original issue reported on code.google.com by john.ice...@gmail.com on 7 Aug 2009 at 3:16

GoogleCodeExporter commented 9 years ago

Original comment by dsalli...@gmail.com on 27 Oct 2009 at 4:25