search

bluegitter / xmemcached

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

大并发情况下频繁出现ClosedChannelException, cache基本上不工作 #90

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
我们的系统并发量比较大，测试时超过200，cache的数据也比较
大，但我们已经限制不超过1M，系统启动后在大并发量情况下
运行几分钟，系统便开始变慢，log里频繁报出ClosedChannelExcepti
on，而且有很多访问超时的异常。请帮忙分析一下这种情况可
能会是什么原因，是配置的参数不合理还是xmemcached有bug呢？

xmemcached初始化代码如下：

MemcachedClientBuilder builder = new 
XMemcachedClientBuilder(AddrUtil.getAddresses(servers.toString()), weights);
builder.setConnectionPoolSize(100);
builder.setSocketOption(StandardSocketOption.SO_RCVBUF, 32 * 1024); // set 
receive buffer as 32K, default is 16K                         
builder.setSocketOption(StandardSocketOption.SO_SNDBUF, 16 * 1024); // set send 
buffer as 16K, default is 8K
builder.getConfiguration().setStatisticsServer(false); // disable connection 
statistics

MemcachedClient mcc = builder.build();
mcc.setConnectTimeout(0);
mcc.setOpTimeout(2000L);
mcc.setOptimizeMergeBuffer(false); // disable the buffer merge
mcc.getTranscoder().setCompressionThreshold(65536);
mcc.setSanitizeKeys(false);

错误日志如下：
2010-08-11 22:07:02,764 Xmemcached-Reactor-14 ERROR 
[net.rubyeye.xmemcached.impl.MemcachedHandler] - XMemcached network layout 
exception
java.nio.channels.ClosedChannelException
    at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:167)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.enableWrite(AbstractNioSession.java:183)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.onEvent(AbstractNioSession.java:412)
    at com.google.code.yanf4j.nio.impl.Reactor.dispatchSessionEvent(Reactor.java:431)
    at com.google.code.yanf4j.nio.impl.Reactor.processRegister(Reactor.java:406)
    at com.google.code.yanf4j.nio.impl.Reactor.beforeSelect(Reactor.java:398)
    at com.google.code.yanf4j.nio.impl.Reactor.run(Reactor.java:102)

2010-08-11 22:07:03,112 MemCachedSet-1-thread-26 ERROR 
[com.sears.wishbook.cache.XMemCachedManager] -  set to xmemcached time out 
java.util.concurrent.TimeoutException: Timed out(2000) waiting for operation
    at net.rubyeye.xmemcached.XMemcachedClient.latchWait(XMemcachedClient.java:2200)
    at net.rubyeye.xmemcached.XMemcachedClient.sendStoreCommand(XMemcachedClient.java:2183)
    at net.rubyeye.xmemcached.XMemcachedClient.set(XMemcachedClient.java:1128)
    at net.rubyeye.xmemcached.XMemcachedClient.set(XMemcachedClient.java:1186)
    at net.rubyeye.xmemcached.XMemcachedClient.set(XMemcachedClient.java:1173)
    at com.sears.wishbook.cache.XMemCachedManager.set(XMemCachedManager.java:102)
    at com.sears.wishbook.cache.MemCachedManager.set(MemCachedManager.java:156)
    at com.sears.tec.cache.MemCacheUtils$1.run(MemCacheUtils.java:32)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)

Original issue reported on code.google.com by draco.y...@gmail.com on 12 Aug 2010 at 3:35

GoogleCodeExporter commented 9 years ago 
不知道你们的cache数据平均大小多大。
其次提供下使用xmc的版本号，memcached的版本号，os信息等。除
了这两个异常之外，有没有其他异常信息。

Original comment by killme2...@gmail.com on 12 Aug 2010 at 3:40

GoogleCodeExporter commented 9 years ago 
使用的是xmc1.2.5，linux系统，16CPU，jboss服务器，JVM的heap size 
12G, 另外一个相关的log:

java.lang.InterruptedException
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:134)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:276)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:188)
    at com.sears.tec.cache.MemCacheUtils$3.run(MemCacheUtils.java:127)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 3:46

GoogleCodeExporter commented 9 years ago 
cache的数据主要是对象数组或集合，平均数据应该是每次100个
对象以上，平均数据量应该大于500K。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 3:48

GoogleCodeExporter commented 9 years ago 
Sorry, 上面贴的log没贴全：

java.lang.InterruptedException
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:134)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:276)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:188)
    at com.sears.tec.cache.MemCacheUtils$3.run(MemCacheUtils.java:127)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.InterruptedException
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1024)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1303)
    at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:253)
    at net.rubyeye.xmemcached.XMemcachedClient.latchWait(XMemcachedClient.java:2198)
    at net.rubyeye.xmemcached.XMemcachedClient.fetch0(XMemcachedClient.java:491)
    at net.rubyeye.xmemcached.XMemcachedClient.get0(XMemcachedClient.java:847)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:805)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:816)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:838)
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:126)

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 3:50

GoogleCodeExporter commented 9 years ago 
ClosedChannelException的意思是连接已经被关闭了。问题可能出现�
��xmc主动关闭了连接或者memcached主动关闭了连接，因此你还需
要查看下日志有没有类似remove 
session这样的字样，查看上下文里是否有其他网络异常或者ERRO
R级别的日志。

Original comment by killme2...@gmail.com on 12 Aug 2010 at 3:54

GoogleCodeExporter commented 9 years ago 
这里需要提及的一点是，我们之前用的java 
memcached，但发现他的代码写的不好，而且会有memory 
leak和频繁创建关闭socket的情况，并且其nio的使用也存在问题�
��所以准备换client。由于java 
memcached不支持访问超时时间的设置，所以对于其访问我们使��
�了线程池，如果其访问在设定时间内未返回结果，就会终止�
��线程。xmemcached本身支持超时时间，我们可以把访问的这个��
�程池去掉，但现在刚进行测试，所以暂时没有去掉，可能会�
��现我们的线程超时后终止的情况，不知道会不会引起xmemcache
d的一些资源没有回收或者一些状态的错误。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 3:56

GoogleCodeExporter commented 9 years ago 
另外可以确定的是memcached 
server没有出现停止或者不能访问的情况，因为我们有监控程��
�在监控所有的memcached 
server的状态，包括能否正常读取和设置数据，监控程序一直��
�正常的。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 4:04

GoogleCodeExporter commented 9 years ago 
有没有类似remove 
session这样的日志？在这个日志前后有没有什么异常？
你们的xmc是不是全局单例的？不需要每次都创建

Original comment by killme2...@gmail.com on 12 Aug 2010 at 5:00

GoogleCodeExporter commented 9 years ago 
2010-08-12 00:10:14,909 MemCachedGet-1-thread-26 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
/157.241.136.45:11211

2010-08-12 00:10:29,139 MemCachedGet-1-thread-8 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
tryprtecgrid1.kdmz.kmart.net/157.241.136.45:11211

2010-08-12 00:10:29,139 MemCachedGet-1-thread-8 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
tryprtecgrid1.kdmz.kmart.net/157.241.136.45:11211
2010-08-12 00:10:29,161 MemCachedGet-1-thread-8 ERROR 
[net.rubyeye.xmemcached.impl.MemcachedHandler] - XMemcached network layout 
exception
java.nio.channels.ClosedChannelException
    at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:167)
    at java.nio.channels.SelectableChannel.register(SelectableChannel.java:254)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.flush0(AbstractNioSession.java:337)
    at com.google.code.yanf4j.nio.impl.NioTCPSession.closeChannel(NioTCPSession.java:317)
    at com.google.code.yanf4j.core.impl.AbstractSession.close(AbstractSession.java:286)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.write0(AbstractNioSession.java:258)
    at com.google.code.yanf4j.core.impl.AbstractSession.write(AbstractSession.java:408)
    at net.rubyeye.xmemcached.impl.MemcachedConnector.send(MemcachedConnector.java:325)
    at net.rubyeye.xmemcached.XMemcachedClient.sendCommand(XMemcachedClient.java:223)
    at net.rubyeye.xmemcached.XMemcachedClient.sendGetMultiCommand(XMemcachedClient.java:1113)
    at net.rubyeye.xmemcached.XMemcachedClient.getMulti0(XMemcachedClient.java:1028)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:908)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:946)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:933)
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:147)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:294)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:230)
    at com.sears.tec.cache.MemCacheUtils$5.run(MemCacheUtils.java:225)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)

2010-08-12 00:10:29,162 Xmemcached-Reactor-0 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - add session: 
/157.241.136.46:11211
2010-08-12 00:10:29,162 MemCachedGet-1-thread-8 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
tryprtecgrid1.kdmz.kmart.net/157.241.136.45:11211
2010-08-12 00:10:29,167 MemCachedGet-1-thread-8 ERROR 
[net.rubyeye.xmemcached.impl.MemcachedHandler] - XMemcached network layout 
exception
java.nio.channels.ClosedChannelException
    at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:167)
    at java.nio.channels.SelectableChannel.register(SelectableChannel.java:254)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.flush0(AbstractNioSession.java:337)
    at com.google.code.yanf4j.nio.impl.NioTCPSession.closeChannel(NioTCPSession.java:317)
    at com.google.code.yanf4j.core.impl.AbstractSession.close(AbstractSession.java:286)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.write0(AbstractNioSession.java:258)
    at com.google.code.yanf4j.core.impl.AbstractSession.write(AbstractSession.java:408)
    at net.rubyeye.xmemcached.impl.MemcachedConnector.send(MemcachedConnector.java:325)
    at net.rubyeye.xmemcached.XMemcachedClient.sendCommand(XMemcachedClient.java:223)
    at net.rubyeye.xmemcached.XMemcachedClient.sendGetMultiCommand(XMemcachedClient.java:1113)
    at net.rubyeye.xmemcached.XMemcachedClient.getMulti0(XMemcachedClient.java:1028)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:908)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:946)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:933)
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:147)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:294)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:230)
    at com.sears.tec.cache.MemCacheUtils$5.run(MemCacheUtils.java:225)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
2010-08-12 00:10:29,168 MemCachedGet-1-thread-8 ERROR 
[com.google.code.yanf4j.core.impl.AbstractSession] - Flush error
java.nio.channels.ClosedChannelException
    at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:167)
    at java.nio.channels.SelectableChannel.register(SelectableChannel.java:254)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.flush0(AbstractNioSession.java:337)
    at com.google.code.yanf4j.nio.impl.NioTCPSession.closeChannel(NioTCPSession.java:317)
    at com.google.code.yanf4j.core.impl.AbstractSession.close(AbstractSession.java:286)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.write0(AbstractNioSession.java:258)
    at com.google.code.yanf4j.core.impl.AbstractSession.write(AbstractSession.java:408)
    at net.rubyeye.xmemcached.impl.MemcachedConnector.send(MemcachedConnector.java:325)
    at net.rubyeye.xmemcached.XMemcachedClient.sendCommand(XMemcachedClient.java:223)
    at net.rubyeye.xmemcached.XMemcachedClient.sendGetMultiCommand(XMemcachedClient.java:1113)
    at net.rubyeye.xmemcached.XMemcachedClient.getMulti0(XMemcachedClient.java:1028)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:908)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:946)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:933)
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:147)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:294)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:230)
    at com.sears.tec.cache.MemCacheUtils$5.run(MemCacheUtils.java:225)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
2010-08-12 00:10:29,168 MemCachedGet-1-thread-8 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
/157.241.136.46:11211
2010-08-12 00:10:29,174 MemCachedGet-1-thread-8 ERROR 
[net.rubyeye.xmemcached.impl.MemcachedHandler] - XMemcached network layout 
exception
java.nio.channels.ClosedChannelException
    at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:167)
    at java.nio.channels.SelectableChannel.register(SelectableChannel.java:254)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.flush0(AbstractNioSession.java:337)
    at com.google.code.yanf4j.nio.impl.NioTCPSession.closeChannel(NioTCPSession.java:317)
    at com.google.code.yanf4j.core.impl.AbstractSession.close(AbstractSession.java:286)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.write0(AbstractNioSession.java:258)
    at com.google.code.yanf4j.core.impl.AbstractSession.write(AbstractSession.java:408)
    at net.rubyeye.xmemcached.impl.MemcachedConnector.send(MemcachedConnector.java:325)
    at net.rubyeye.xmemcached.XMemcachedClient.sendCommand(XMemcachedClient.java:223)
    at net.rubyeye.xmemcached.XMemcachedClient.sendGetMultiCommand(XMemcachedClient.java:1113)
    at net.rubyeye.xmemcached.XMemcachedClient.getMulti0(XMemcachedClient.java:1028)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:908)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:946)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:933)
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:147)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:294)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:230)
    at com.sears.tec.cache.MemCacheUtils$5.run(MemCacheUtils.java:225)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
2010-08-12 00:10:29,175 MemCachedGet-1-thread-8 ERROR 
[com.google.code.yanf4j.core.impl.AbstractSession] - Flush error
java.nio.channels.ClosedChannelException
    at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:167)
    at java.nio.channels.SelectableChannel.register(SelectableChannel.java:254)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.flush0(AbstractNioSession.java:337)
    at com.google.code.yanf4j.nio.impl.NioTCPSession.closeChannel(NioTCPSession.java:317)
    at com.google.code.yanf4j.core.impl.AbstractSession.close(AbstractSession.java:286)
    at com.google.code.yanf4j.nio.impl.AbstractNioSession.write0(AbstractNioSession.java:258)
    at com.google.code.yanf4j.core.impl.AbstractSession.write(AbstractSession.java:408)
    at net.rubyeye.xmemcached.impl.MemcachedConnector.send(MemcachedConnector.java:325)
    at net.rubyeye.xmemcached.XMemcachedClient.sendCommand(XMemcachedClient.java:223)
    at net.rubyeye.xmemcached.XMemcachedClient.sendGetMultiCommand(XMemcachedClient.java:1113)
    at net.rubyeye.xmemcached.XMemcachedClient.getMulti0(XMemcachedClient.java:1028)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:908)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:946)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:933)
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:147)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:294)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:230)
    at com.sears.tec.cache.MemCacheUtils$5.run(MemCacheUtils.java:225)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 5:16

GoogleCodeExporter commented 9 years ago 
里面有很多这样的remove session和add session的log，同时还有flush 
error，我用的是单例模式。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 5:18

GoogleCodeExporter commented 9 years ago 
log里可以看出这些连接在不停的关闭和创建，而且不确定flush
 error会在什么情况下出现。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 5:20

GoogleCodeExporter commented 9 years ago 
你们连的是memcached还是其他？

Original comment by killme2...@gmail.com on 12 Aug 2010 at 5:34

GoogleCodeExporter commented 9 years ago 
memcached 1.4版

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 6:11

GoogleCodeExporter commented 9 years ago 
在下面日志之前有什么日志？
2010-08-12 00:10:14,909 MemCachedGet-1-thread-26 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
/157.241.136.45:11211

2010-08-12 00:10:29,139 MemCachedGet-1-thread-8 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
tryprtecgrid1.kdmz.kmart.net/157.241.136.45:11211

2010-08-12 00:10:29,139 MemCachedGet-1-thread-8 WARN 
[com.google.code.yanf4j.core.impl.AbstractController] - remove session 
tryprtecgrid1.kdmz.kmart.net/157.241.136.45:11211

在remove session之前有什么异常吗？

Original comment by killme2...@gmail.com on 12 Aug 2010 at 7:29

GoogleCodeExporter commented 9 years ago 
之前曾有线程被终止的异常：

java.lang.InterruptedException
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:134)
    at com.sears.wishbook.cache.MemCachedManager.getCachedData(MemCachedManager.java:276)
    at com.sears.wishbook.cache.MemCachedManager.get(MemCachedManager.java:188)
    at com.sears.tec.cache.MemCacheUtils$3.run(MemCacheUtils.java:127)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.InterruptedException
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1024)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1303)
    at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:253)
    at net.rubyeye.xmemcached.XMemcachedClient.latchWait(XMemcachedClient.java:2198)
    at net.rubyeye.xmemcached.XMemcachedClient.fetch0(XMemcachedClient.java:491)
    at net.rubyeye.xmemcached.XMemcachedClient.get0(XMemcachedClient.java:847)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:805)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:816)
    at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:838)
    at com.sears.wishbook.cache.XMemCachedManager.get(XMemCachedManager.java:126)

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 7:47

GoogleCodeExporter commented 9 years ago 
线程被终止掉是因为等待超时：
2010-08-12 00:10:14,789 TieredQuery-1-thread-29 ERROR 
[com.sears.tec.concurrent.ThreadTaskManager] - Wait for thread tasks termiation 
failed since the waiting thread itself was interrupted
java.lang.InterruptedException
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1024)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1303)
    at java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:557)
    at com.sears.tec.concurrent.ThreadTaskManager.waitAll(ThreadTaskManager.java:52)
    at com.sears.tec.concurrent.ThreadTaskManager.waitAllAndTerminate(ThreadTaskManager.java:81)
    at com.sears.tec.concurrent.ThreadTaskUtils.run(ThreadTaskUtils.java:86)
    at com.sears.tec.cache.MemCacheUtils.get(MemCacheUtils.java:290)
    at com.sears.tec.cache.MemCacheUtils.internalGet(MemCacheUtils.java:131)
    at com.sears.tec.cache.MemCacheUtils.get(MemCacheUtils.java:98)
    at com.sears.tec.db.SQLHelper.executeQuery(SQLHelper.java:389)
    at com.sears.tec.db.SQLHelper.executeQuery(SQLHelper.java:614)
    at com.sears.tec.daoimpl.JdbcDAOHelper.executeQuery(JdbcDAOHelper.java:355)
    at com.sears.tec.daoimpl.JdbcDAOHelper.executeQuery(JdbcDAOHelper.java:318)
    at com.sears.tec.daoimpl.JdbcDAOBase.executeQuery(JdbcDAOBase.java:326)
    at com.sears.tec.daoimpl.ConceptJdbcDAO.findConceptsByTieredQueryConfig(ConceptJdbcDAO.java:586)
    at com.sears.tec.algorithm.TieredQueryHelper$1.run(TieredQueryHelper.java:165)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:36)
    at com.sears.tec.concurrent.ThreadTaskProxy.call(ThreadTaskProxy.java:8)
    at com.sears.tec.concurrent.CallableWrapper.call(CallableWrapper.java:33)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.sears.tec.concurrent.SemaphoreFutureTask.run(SemaphoreFutureTask.java:27)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 7:49

GoogleCodeExporter commented 9 years ago 
如果调用xmemcached的get或者set的线程被终止掉，是否可能会导�
��上述问题？

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 7:57

GoogleCodeExporter commented 9 years ago 
可以的话，请将完整的日志作为附件传送上来，包括从启动��
�故障时间内的日志。
或者发到我的邮箱 killme2008@gmail.com

理论上说线程中断不会有影响的。

Original comment by killme2...@gmail.com on 12 Aug 2010 at 8:05

GoogleCodeExporter commented 9 years ago 
并且请确认你的代码没有调用MemcachedClient.shutdown();

Original comment by killme2...@gmail.com on 12 Aug 2010 at 8:29

GoogleCodeExporter commented 9 years ago 
附件为系统启动后大约5分钟时得到的所有WARN及以上级别的log

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 8:50

Attachments:

GoogleCodeExporter commented 9 years ago 
我根本还没来得及写调用shutdown方法的代码。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 8:52

GoogleCodeExporter commented 9 years ago 
hi，知道原因了，从日志上分析，是因为中断关闭了nio的channe
l，在写消息的时候。你的代码需要调整，避免中断调用xmc的�
��程。
另外，我看到你好像用了非常大的线程池，nio的线程池不建��
�设置太大，通常来说单连接已经足够。

Original comment by killme2...@gmail.com on 12 Aug 2010 at 9:04

GoogleCodeExporter commented 9 years ago 
我开始也怀疑是线程中断引起的，之前线程池设置的20，但一
启动很快就出问题，所以加大到100。现在我们有很多算法在��
�同的线程里运行，而且每种算法都有超时时间的限制，如果�
��时了还未做完，就需要终止该算法，而在每个算法里又会有
大量访问memcached的情况，有没有什么好的建议像你说的在不��
�止线程的情况下可以让操作终止的。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 9:08

GoogleCodeExporter commented 9 years ago 
你这个比较难办了。不使用中断，不知道你们的任务是否都��
�阻塞的，能否改成使用标志位来停止线程。xmc目前的版本，�
��果中断，确实会关闭连接。这个以后会考虑提供一个选项来
屏蔽中断，但是目前没有办法。

Original comment by killme2...@gmail.com on 12 Aug 2010 at 9:19

GoogleCodeExporter commented 9 years ago 
我们的任务差不多都是阻塞的，都会执行数据库查询，而好��
�查询比较耗时，在规定的时间内不能结束就只能通过中断。�
��想问下xmemcached自己提供的超时功能，如果超时了get或set任��
�本身会终止吗？

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 9:54

GoogleCodeExporter commented 9 years ago 
超时会抛出java.util.TimeoutExcetpion的异常，然后如果请求还没发
出将取消，如果发出，那么在响应到达的时候将忽略。

Original comment by killme2...@gmail.com on 12 Aug 2010 at 9:56

GoogleCodeExporter commented 9 years ago 
Got it, 我再仔细想想我的这种情况怎么处理，非常感谢！！！

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 10:02

GoogleCodeExporter commented 9 years ago 
你再试试有没有其他的解决方案，如果实在不行，我可以在1.
2.5上立即改个屏蔽中断的版本给你测试。

Original comment by killme2...@gmail.com on 12 Aug 2010 at 10:06

GoogleCodeExporter commented 9 years ago 
好的，太感谢了，不行的话我再给你发邮件。

Original comment by draco.y...@gmail.com on 12 Aug 2010 at 10:09

GoogleCodeExporter commented 9 years ago 
现在情况如何？

Original comment by killme2...@gmail.com on 16 Aug 2010 at 12:36

GoogleCodeExporter commented 9 years ago 
我已经把我们的代码修改为在主线程被终止的时候，不终止��
�问cache的子线程，之前socket不停关闭的问题没有重现。

Original comment by draco.y...@gmail.com on 18 Aug 2010 at 2:18

GoogleCodeExporter commented 9 years ago 
好的，这个bug我会在下个版本修复。

Original comment by killme2...@gmail.com on 18 Aug 2010 at 2:21

GoogleCodeExporter commented 9 years ago 
我也碰到这个问题，不知道解决了没有？
java.util.concurrent.TimeoutException: Timed out waiting for operation
        at net.rubyeye.xmemcached.XMemcachedClient.getMulti0(XMemcachedClient.java:1036)
        at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:908)
        at net.rubyeye.xmemcached.XMemcachedClient.get(XMemcachedClient.java:946)

Original comment by fnainv...@googlemail.com on 6 Sep 2010 at 6:53

GoogleCodeExporter commented 9 years ago

Original comment by killme2...@gmail.com on 15 Oct 2010 at 1:24

GoogleCodeExporter commented 9 years ago 
This issue was closed by revision r654.

Original comment by killme2...@gmail.com on 16 Oct 2010 at 3:23

GoogleCodeExporter commented 9 years ago 
1.2.6.1已经发布，这个问题已经彻底解决

Original comment by killme2...@gmail.com on 17 Oct 2010 at 7:40

GoogleCodeExporter commented 9 years ago 
这个问题还是没有解决啊～

Original comment by tujiao....@gmail.com on 30 Dec 2010 at 5:25

GoogleCodeExporter commented 9 years ago 
这个问题在1.2.6.2上已经解决了。

Original comment by killme2...@gmail.com on 30 Dec 2010 at 5:41

GoogleCodeExporter commented 9 years ago 
http://hi.baidu.com/zhenuu/blog/item/a2d5a94bead636e283025c09.html

这里有一个解决方法～～

Original comment by tujiao....@gmail.com on 30 Dec 2010 at 6:48

GoogleCodeExporter commented 9 years ago 
1.4.2 又出现了这个问题，每隔一段时间就 Remove a session 和 Add 
a session，几乎没有其他 Exception。

Original comment by cowboy...@gmail.com on 13 Dec 2013 at 7:28