You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by Qiang Tian <ti...@gmail.com> on 2014/06/06 10:09:57 UTC
Re: regionserver 60020 timeout
it looks to me the listener select a reader busy in reading...currently it
is selected by round robin:
// The method that will return the next reader to work with
// Simplistic implementation of round robin for now
Reader getReader() {
currentReader = (currentReader + 1) % readers.length;
return readers[currentReader];
Did you set ipc.server.read.threadpool.size? by default it is 10. maybe
increasing it can lower the chance of hitting busy reader...
this.readThreads = conf.getInt("ipc.server.read.threadpool.size", 10);
On Fri, Jun 6, 2014 at 2:35 PM, sunweiwei <su...@asiainfo-linkage.com>
wrote:
> Hi
>
> I find some 60000 millis timeout in master log, when master connect
> regionserver's 60020 port. Log like this:
>
> because java.net.SocketTimeoutException: 60000 millis timeout while waiting
> for channel to be ready for read. ch :
> java.nio.channels.SocketChannel[connected local=/132.228.248.61:34835
> remote=dsjhd074/132.228.248.84:60020]
>
> at org.apache.hadoop.hbase.ipc.RpcClient.wrapException(RpcClient.java:1475)
>
> at org.apache.hadoop.hbase.ipc.RpcClient.call(RpcClient.java:1450)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcClient.callBlockingMethod(RpcClient.java:1650
> )
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcClient$BlockingRpcChannelImplementation.callB
> lockingMethod(RpcClient.java:1708)
>
> at
>
> org.apache.hadoop.hbase.protobuf.generated.AdminProtos$AdminService$Blocking
> Stub.openRegion(AdminProtos.java:20595)
>
> at
>
> org.apache.hadoop.hbase.master.ServerManager.sendRegionOpen(ServerManager.ja
> va:628)
>
> at
>
> org.apache.hadoop.hbase.master.AssignmentManager.assign(AssignmentManager.ja
> va:1901)
>
> at
>
> org.apache.hadoop.hbase.master.AssignmentManager.access$300(AssignmentManage
> r.java:106)
>
> at
>
> org.apache.hadoop.hbase.master.AssignmentManager$2.process(AssignmentManager
> .java:660)
>
> at
> org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128)
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
> va:886)
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
> 08)
>
> at java.lang.Thread.run(Thread.java:662)
>
>
>
> And I find listener,port 60020 is waiting to lock <0x000000041ae290d8> in
> regionserver's jstack log. Is that ok? Thanks
>
> "RpcServer.reader=4,port=60020" daemon prio=10 tid=0x00007fade53c0000
> nid=0x22d8c runnable [0x00007fadb8b32000]
>
> java.lang.Thread.State: RUNNABLE
>
> 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:198)
>
> at sun.nio.ch.IOUtil.read(IOUtil.java:171)
>
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:243)
>
> - locked <0x000000041b1c78c0> (a java.lang.Object)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer.channelIO(RpcServer.java:2402)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer.channelRead(RpcServer.java:2368)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Connection.readAndProcess(RpcServer.ja
> va:1476)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.doRead(RpcServer.java:770)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.doRunLoop(RpcServer.ja
> va:563)
>
> - locked <0x000000041ae290d8> (a
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.run(RpcServer.java:538
> )
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
> va:886)
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
> 08)
>
> at java.lang.Thread.run(Thread.java:662)
>
>
>
> "RpcServer.listener,port=60020" daemon prio=10 tid=0x00007fadd4426800
> nid=0x22db3 waiting for monitor entry [0x00007fadb658a000]
>
> java.lang.Thread.State: BLOCKED (on object monitor)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.registerChannel(RpcSer
> ver.java:593)
>
> - waiting to lock <0x000000041ae290d8> (a
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.doAccept(RpcServer.java:745)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.run(RpcServer.java:668)
>
>
Re: 答复: regionserver 60020 timeout
Posted by Ted Yu <yu...@gmail.com>.
Weiwei:
w.r.t. ClosedByInterruptException you saw in region server log, see the
following in RpcServer#stop():
running = false;
listener.interrupt();
Cheers
On Fri, Jun 6, 2014 at 3:56 AM, sunweiwei <su...@asiainfo-linkage.com>
wrote:
> Thanks. I will try.
>
> And when stop the regionserver, I see logs:
> 2014-06-06 18:30:37,354 WARN [RpcServer.reader=4,port=60020]
> ipc.RpcServer: RpcServer.listener,port=60020: count of bytes read: 0
> java.nio.channels.ClosedByInterruptException
> at
> java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:270)
> at
> org.apache.hadoop.hbase.ipc.RpcServer.channelRead(RpcServer.java:2368)
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Connection.readAndProcess(RpcServer.java:1476)
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.doRead(RpcServer.java:770)
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.doRunLoop(RpcServer.java:563)
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.run(RpcServer.java:538)
> 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:662)
> 2014-06-06 18:30:37,354 INFO [RpcServer.responder] ipc.RpcServer:
> RpcServer.responder: stopping
>
>
> -----邮件原件-----
> 发件人: Qiang Tian [mailto:tianq01@gmail.com]
> 发送时间: 2014年6月6日 16:10
> 收件人: user@hbase.apache.org
> 主题: Re: regionserver 60020 timeout
>
> it looks to me the listener select a reader busy in reading...currently it
> is selected by round robin:
>
> // The method that will return the next reader to work with
> // Simplistic implementation of round robin for now
> Reader getReader() {
> currentReader = (currentReader + 1) % readers.length;
> return readers[currentReader];
>
>
> Did you set ipc.server.read.threadpool.size? by default it is 10. maybe
> increasing it can lower the chance of hitting busy reader...
>
> this.readThreads = conf.getInt("ipc.server.read.threadpool.size", 10);
>
>
>
> On Fri, Jun 6, 2014 at 2:35 PM, sunweiwei <su...@asiainfo-linkage.com>
> wrote:
>
> > Hi
> >
> > I find some 60000 millis timeout in master log, when master connect
> > regionserver's 60020 port. Log like this:
> >
> > because java.net.SocketTimeoutException: 60000 millis timeout while
> waiting
> > for channel to be ready for read. ch :
> > java.nio.channels.SocketChannel[connected local=/132.228.248.61:34835
> > remote=dsjhd074/132.228.248.84:60020]
> >
> > at
> org.apache.hadoop.hbase.ipc.RpcClient.wrapException(RpcClient.java:1475)
> >
> > at
> org.apache.hadoop.hbase.ipc.RpcClient.call(RpcClient.java:1450)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.ipc.RpcClient.callBlockingMethod(RpcClient.java:1650
> > )
> >
> > at
> >
> >
> org.apache.hadoop.hbase.ipc.RpcClient$BlockingRpcChannelImplementation.callB
> > lockingMethod(RpcClient.java:1708)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.protobuf.generated.AdminProtos$AdminService$Blocking
> > Stub.openRegion(AdminProtos.java:20595)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.master.ServerManager.sendRegionOpen(ServerManager.ja
> > va:628)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.master.AssignmentManager.assign(AssignmentManager.ja
> > va:1901)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.master.AssignmentManager.access$300(AssignmentManage
> > r.java:106)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.master.AssignmentManager$2.process(AssignmentManager
> > .java:660)
> >
> > at
> > org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128)
> >
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
> > va:886)
> >
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
> > 08)
> >
> > at java.lang.Thread.run(Thread.java:662)
> >
> >
> >
> > And I find listener,port 60020 is waiting to lock <0x000000041ae290d8>
> in
> > regionserver's jstack log. Is that ok? Thanks
> >
> > "RpcServer.reader=4,port=60020" daemon prio=10 tid=0x00007fade53c0000
> > nid=0x22d8c runnable [0x00007fadb8b32000]
> >
> > java.lang.Thread.State: RUNNABLE
> >
> > 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:198)
> >
> > at sun.nio.ch.IOUtil.read(IOUtil.java:171)
> >
> > at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:243)
> >
> > - locked <0x000000041b1c78c0> (a java.lang.Object)
> >
> > at
> > org.apache.hadoop.hbase.ipc.RpcServer.channelIO(RpcServer.java:2402)
> >
> > at
> > org.apache.hadoop.hbase.ipc.RpcServer.channelRead(RpcServer.java:2368)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.ipc.RpcServer$Connection.readAndProcess(RpcServer.ja
> > va:1476)
> >
> > at
> > org.apache.hadoop.hbase.ipc.RpcServer$Listener.doRead(RpcServer.java:770)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.doRunLoop(RpcServer.ja
> > va:563)
> >
> > - locked <0x000000041ae290d8> (a
> > org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.run(RpcServer.java:538
> > )
> >
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
> > va:886)
> >
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
> > 08)
> >
> > at java.lang.Thread.run(Thread.java:662)
> >
> >
> >
> > "RpcServer.listener,port=60020" daemon prio=10 tid=0x00007fadd4426800
> > nid=0x22db3 waiting for monitor entry [0x00007fadb658a000]
> >
> > java.lang.Thread.State: BLOCKED (on object monitor)
> >
> > at
> >
> >
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.registerChannel(RpcSer
> > ver.java:593)
> >
> > - waiting to lock <0x000000041ae290d8> (a
> > org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader)
> >
> > at
> >
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.doAccept(RpcServer.java:745)
> >
> > at
> > org.apache.hadoop.hbase.ipc.RpcServer$Listener.run(RpcServer.java:668)
> >
> >
>
>
答复: regionserver 60020 timeout
Posted by sunweiwei <su...@asiainfo-linkage.com>.
Thanks. I will try.
And when stop the regionserver, I see logs:
2014-06-06 18:30:37,354 WARN [RpcServer.reader=4,port=60020] ipc.RpcServer: RpcServer.listener,port=60020: count of bytes read: 0
java.nio.channels.ClosedByInterruptException
at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:270)
at org.apache.hadoop.hbase.ipc.RpcServer.channelRead(RpcServer.java:2368)
at org.apache.hadoop.hbase.ipc.RpcServer$Connection.readAndProcess(RpcServer.java:1476)
at org.apache.hadoop.hbase.ipc.RpcServer$Listener.doRead(RpcServer.java:770)
at org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.doRunLoop(RpcServer.java:563)
at org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.run(RpcServer.java:538)
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:662)
2014-06-06 18:30:37,354 INFO [RpcServer.responder] ipc.RpcServer: RpcServer.responder: stopping
-----邮件原件-----
发件人: Qiang Tian [mailto:tianq01@gmail.com]
发送时间: 2014年6月6日 16:10
收件人: user@hbase.apache.org
主题: Re: regionserver 60020 timeout
it looks to me the listener select a reader busy in reading...currently it
is selected by round robin:
// The method that will return the next reader to work with
// Simplistic implementation of round robin for now
Reader getReader() {
currentReader = (currentReader + 1) % readers.length;
return readers[currentReader];
Did you set ipc.server.read.threadpool.size? by default it is 10. maybe
increasing it can lower the chance of hitting busy reader...
this.readThreads = conf.getInt("ipc.server.read.threadpool.size", 10);
On Fri, Jun 6, 2014 at 2:35 PM, sunweiwei <su...@asiainfo-linkage.com>
wrote:
> Hi
>
> I find some 60000 millis timeout in master log, when master connect
> regionserver's 60020 port. Log like this:
>
> because java.net.SocketTimeoutException: 60000 millis timeout while waiting
> for channel to be ready for read. ch :
> java.nio.channels.SocketChannel[connected local=/132.228.248.61:34835
> remote=dsjhd074/132.228.248.84:60020]
>
> at org.apache.hadoop.hbase.ipc.RpcClient.wrapException(RpcClient.java:1475)
>
> at org.apache.hadoop.hbase.ipc.RpcClient.call(RpcClient.java:1450)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcClient.callBlockingMethod(RpcClient.java:1650
> )
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcClient$BlockingRpcChannelImplementation.callB
> lockingMethod(RpcClient.java:1708)
>
> at
>
> org.apache.hadoop.hbase.protobuf.generated.AdminProtos$AdminService$Blocking
> Stub.openRegion(AdminProtos.java:20595)
>
> at
>
> org.apache.hadoop.hbase.master.ServerManager.sendRegionOpen(ServerManager.ja
> va:628)
>
> at
>
> org.apache.hadoop.hbase.master.AssignmentManager.assign(AssignmentManager.ja
> va:1901)
>
> at
>
> org.apache.hadoop.hbase.master.AssignmentManager.access$300(AssignmentManage
> r.java:106)
>
> at
>
> org.apache.hadoop.hbase.master.AssignmentManager$2.process(AssignmentManager
> .java:660)
>
> at
> org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128)
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
> va:886)
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
> 08)
>
> at java.lang.Thread.run(Thread.java:662)
>
>
>
> And I find listener,port 60020 is waiting to lock <0x000000041ae290d8> in
> regionserver's jstack log. Is that ok? Thanks
>
> "RpcServer.reader=4,port=60020" daemon prio=10 tid=0x00007fade53c0000
> nid=0x22d8c runnable [0x00007fadb8b32000]
>
> java.lang.Thread.State: RUNNABLE
>
> 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:198)
>
> at sun.nio.ch.IOUtil.read(IOUtil.java:171)
>
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:243)
>
> - locked <0x000000041b1c78c0> (a java.lang.Object)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer.channelIO(RpcServer.java:2402)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer.channelRead(RpcServer.java:2368)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Connection.readAndProcess(RpcServer.ja
> va:1476)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.doRead(RpcServer.java:770)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.doRunLoop(RpcServer.ja
> va:563)
>
> - locked <0x000000041ae290d8> (a
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.run(RpcServer.java:538
> )
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja
> va:886)
>
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9
> 08)
>
> at java.lang.Thread.run(Thread.java:662)
>
>
>
> "RpcServer.listener,port=60020" daemon prio=10 tid=0x00007fadd4426800
> nid=0x22db3 waiting for monitor entry [0x00007fadb658a000]
>
> java.lang.Thread.State: BLOCKED (on object monitor)
>
> at
>
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader.registerChannel(RpcSer
> ver.java:593)
>
> - waiting to lock <0x000000041ae290d8> (a
> org.apache.hadoop.hbase.ipc.RpcServer$Listener$Reader)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.doAccept(RpcServer.java:745)
>
> at
> org.apache.hadoop.hbase.ipc.RpcServer$Listener.run(RpcServer.java:668)
>
>