here are the logs. (pretty much same on all region servers)
-------------------------------------------------------------------------------------------------------------
2016-06-23 03:18:07,187 ERROR
[B.defaultRpcServer.handler=80,queue=0,port=16020] parallel.BaseTaskRunner:
Found a failed task because: org.apache.hadoop.hbase.DoNotRetry
IOException: ERROR 2008 (INT10): ERROR 2008 (INT10): Unable to find cached
index metadata. key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
Index update failed
java.util.concurrent.ExecutionException:
org.apache.hadoop.hbase.DoNotRetryIOException: ERROR 2008 (INT10): ERROR
2008 (INT10): Unable to find cached index metadata.
key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
Index update failed
at
com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:289)
at
com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:276)
at
com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:111)
at
org.apache.phoenix.hbase.index.parallel.BaseTaskRunner.submit(BaseTaskRunner.java:66)
at
org.apache.phoenix.hbase.index.parallel.BaseTaskRunner.submitUninterruptible(BaseTaskRunner.java:99)
at
org.apache.phoenix.hbase.index.builder.IndexBuildManager.getIndexUpdate(IndexBuildManager.java:140)
at
org.apache.phoenix.hbase.index.Indexer.preBatchMutateWithExceptions(Indexer.java:274)
at
org.apache.phoenix.hbase.index.Indexer.preBatchMutate(Indexer.java:203)
at
org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost$35.call(RegionCoprocessorHost.java:991)
at
org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost$RegionOperation.call(RegionCoprocessorHost.java:1673)
at
org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.execOperation(RegionCoprocessorHost.java:1748)
at
org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.execOperation(RegionCoprocessorHost.java:1705)
at
org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.preBatchMutate(RegionCoprocessorHost.java:987)
at
org.apache.hadoop.hbase.regionserver.HRegion.doMiniBatchMutation(HRegion.java:3027)
at
org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2801)
at
org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2743)
at
org.apache.hadoop.hbase.regionserver.RSRpcServices.doBatchOp(RSRpcServices.java:692)
at
org.apache.hadoop.hbase.regionserver.RSRpcServices.doNonAtomicRegionMutation(RSRpcServices.java:654)
at
org.apache.hadoop.hbase.regionserver.RSRpcServices.multi(RSRpcServices.java:2031)
at
org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:32213)
at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2114)
at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:101)
at
org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:130)
at
org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:107)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.hadoop.hbase.DoNotRetryIOException: ERROR 2008
(INT10): ERROR 2008 (INT10): Unable to find cached index metadata.
key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
Index update failed
at
org.apache.phoenix.util.ServerUtil.createIOException(ServerUtil.java:76)
at
org.apache.phoenix.util.ServerUtil.throwIOException(ServerUtil.java:52)
at
org.apache.phoenix.index.PhoenixIndexCodec.getIndexMaintainers(PhoenixIndexCodec.java:102)
at
org.apache.phoenix.index.PhoenixIndexCodec.getIndexUpdates(PhoenixIndexCodec.java:128)
at
org.apache.phoenix.index.PhoenixIndexCodec.getIndexDeletes(PhoenixIndexCodec.java:117)
at
org.apache.phoenix.hbase.index.covered.CoveredColumnsIndexBuilder.addDeleteUpdatesToMap(CoveredColumnsIndexBuilder.java:403)
at
org.apache.phoenix.hbase.index.covered.CoveredColumnsIndexBuilder.addCleanupForCurrentBatch(CoveredColumnsIndexBuilder.java:287)
at
org.apache.phoenix.hbase.index.covered.CoveredColumnsIndexBuilder.addMutationsForBatch(CoveredColumnsIndexBuilder.java:239)
at
org.apache.phoenix.hbase.index.covered.CoveredColumnsIndexBuilder.batchMutationAndAddUpdates(CoveredColumnsIndexBuilder.java:136)
at
org.apache.phoenix.hbase.index.covered.CoveredColumnsIndexBuilder.getIndexUpdate(CoveredColumnsIndexBuilder.java:99)
at
org.apache.phoenix.hbase.index.builder.IndexBuildManager$1.call(IndexBuildManager.java:133)
at
org.apache.phoenix.hbase.index.builder.IndexBuildManager$1.call(IndexBuildManager.java:129)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
... 1 more
Caused by: java.sql.SQLException: ERROR 2008 (INT10): Unable to find cached
index metadata. key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
at
org.apache.phoenix.exception.SQLExceptionCode$Factory$1.newException(SQLExceptionCode.java:396)
at
org.apache.phoenix.exception.SQLExceptionInfo.buildException(SQLExceptionInfo.java:145)
at
org.apache.phoenix.index.PhoenixIndexCodec.getIndexMaintainers(PhoenixIndexCodec.java:100)
che.hadoop.hbase.DoNotRetryIOException: ERROR 2008 (INT10): ERROR 2008
(INT10): Unable to find cached index metadata. key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
Index update failed
2016-06-23 03:18:07,193 ERROR
[B.defaultRpcServer.handler=80,queue=0,port=16020]
builder.IndexBuildManager: Found a failed index update!
2016-06-23 03:18:07,194 INFO
[B.defaultRpcServer.handler=80,queue=0,port=16020]
util.IndexManagementUtil: Rethrowing
org.apache.hadoop.hbase.DoNotRetryIOException: ERROR 2008 (INT10): ERROR
2008 (INT10): Unable to find cached index metadata.
key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
Index update failed
2016-06-23 03:18:07,373 INFO
[B.defaultRpcServer.handler=70,queue=0,port=16020]
util.IndexManagementUtil: Rethrowing
org.apache.hadoop.hbase.DoNotRetryIOException: ERROR 2008 (INT10): ERROR
2008 (INT10): Unable to find cached index metadata.
key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
Index update failed
2016-06-23 03:18:07,385 INFO
[B.defaultRpcServer.handler=0,queue=0,port=16020] util.IndexManagementUtil:
Rethrowing org.apache.hadoop.hbase.DoNotRetryIOException: ERROR 2008
(INT10): ERROR 2008 (INT10): Unable to find cached index metadata.
key=8709114428974824565
region=BIDDING_EVENTS_PROD,\x81\xB4\xE8\x1BN\x81\xB4\xE0\x00\x00\x00\x00\x00\x00\x00\x00,1459280123030.0964a4ebb61c82093783197cb3395799.
Index update failed
2016-06-23 03:18:07,432 WARN
[B.defaultRpcServer.handler=80,queue=0,port=16020] ipc.RpcServer:
(responseTooSlow):
{"call":"Multi(org.apache.hadoop.hbase.protobuf.generated.ClientProtos$MultiRequest)","starttimems":1466651762838,"responsesize":6135137,"method":"Multi","processingtimems":124593,"client":"
10.5.2.119:37665","queuetimems":0,"class":"HRegionServer"}
2016-06-23 03:18:07,472 WARN
[B.defaultRpcServer.handler=70,queue=0,port=16020] ipc.RpcServer:
(responseTooSlow):
{"call":"Multi(org.apache.hadoop.hbase.protobuf.generated.ClientProtos$MultiRequest)","starttimems":1466651822923,"responsesize":7892321,"method":"Multi","processingtimems":64548,"client":"
10.5.2.119:37665","queuetimems":0,"class":"HRegionServer"}
2016-06-23 03:18:10,089 WARN
[B.defaultRpcServer.handler=10,queue=0,port=16020] regionserver.HRegion:
Failed getting lock in batch put,
row=\xE2\xF6\xA4=\x98(\xD6\x91\xD03\xE3\x1D\xBCrQ\xC9
java.io.IOException: Timed out waiting for lock for row:
\xE2\xF6\xA4=\x98(\xD6\x91\xD03\xE3\x1D\xBCrQ\xC9
at
org.apache.hadoop.hbase.regionserver.HRegion.getRowLockInternal(HRegion.java:5051)
at
org.apache.hadoop.hbase.regionserver.HRegion.doMiniBatchMutation(HRegion.java:2944)
at
org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2801)
at
org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2743)
at
org.apache.hadoop.hbase.regionserver.RSRpcServices.doBatchOp(RSRpcServices.java:692)
at
org.apache.hadoop.hbase.regionserver.RSRpcServices.doNonAtomicRegionMutation(RSRpcServices.java:654)
at
org.apache.hadoop.hbase.regionserver.RSRpcServices.multi(RSRpcServices.java:2031)
at
org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:32213)
at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2114)
at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:101)
at
org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:130)
at
org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:107)
at java.lang.Thread.run(Thread.java:745)
2016-06-23 03:18:10,540 INFO [sync.1] wal.FSHLog: Slow sync cost: 620 ms,
current pipeline:
[DatanodeInfoWithStorage[10.5.2.225:50010,DS-4fb755f7-6c7d-457b-b088-bb6733d70cca,DISK],
DatanodeInfoWithStorage[10.5.2.48:50010,DS-1fc61d0b-018a-45c6-b48c-a6404d802deb,DISK],
DatanodeInfoWithStorage[10.5.2.165:50010
,DS-b6355df6-9678-4350-936d-749ad597cbe9,DISK]]
-------------------------------------------------------------------------------------------------------------
On Thu, Jun 23, 2016 at 1:52 PM, rajeshb...@apache.org <
chrajeshbab...@gmail.com> wrote:
> +user@phoenix
>
> Hi Vishnu,
>
> Can you try restarting the region server where you are seeing the timeout
> on rowlocks. Would be helpful if you share RS logs.
> Can you provide the details like what kind of operations done before
> restart and would you like the share the schemas tables.
>
> Thanks,
> Rajeshbabu.
>
> On Thu, Jun 23, 2016 at 9:31 AM, vishnu rao <jaihind...@gmail.com> wrote:
>
> > i tried the following:
> >
> > 1) truncating system stats did not work.
> > 2) phoenix.stats.useCurrentTime=false
> >
> > but no luck - the wait time increased even further
> >
> > On Thu, Jun 23, 2016 at 9:04 AM, vishnu rao <jaihind...@gmail.com>
> wrote:
> >
> > > Hi Biju
> > >
> > > Yes local index
> > >
> > > . It all started when 1 box crashed.
> > >
> > > When I brought up a new one the error was localized to the new box.
> > >
> > > After cluster restart - it's spread to all servers.
> > >
> > > I shall attempt to clear system stats and increase meta cache size
> > > Vishnu,
> > > Are you using "local index" on any of the tables? We have seen
> > similar
> > > issues while using "local index".
> > >
> > > On Wed, Jun 22, 2016 at 12:25 PM, vishnu rao <jaihind...@gmail.com>
> > wrote:
> > >
> > > > the server dies when trying to take the thread dump.
> > > >
> > > > i believe i am experiencing this bug
> > > >
> > > > https://issues.apache.org/jira/browse/PHOENIX-2508
> > > >
> > > > On Wed, Jun 22, 2016 at 5:03 PM, Heng Chen <heng.chen.1...@gmail.com
> >
> > > > wrote:
> > > >
> > > > > which thread hold the row lock? could you dump the jstack with
> > 'jstack
> > > -l
> > > > > pid' ?
> > > > >
> > > > > 2016-06-22 16:14 GMT+08:00 vishnu rao <jaihind...@gmail.com>:
> > > > >
> > > > > > hi Heng.
> > > > > >
> > > > > > 2016-06-22 08:13:42,256 WARN
> > > > > > [B.defaultRpcServer.handler=32,queue=2,port=16020]
> > > > regionserver.HRegion:
> > > > > > Failed getting lock in batch put,
> > > > > > row=\x01\xD6\xFD\xC9\xDC\xE4\x08\xC4\x0D\xBESM\xC2\x82\x14Z
> > > > > >
> > > > > > java.io.IOException: Timed out waiting for lock for row:
> > > > > > \x01\xD6\xFD\xC9\xDC\xE4\x08\xC4\x0D\xBESM\xC2\x82\x14Z
> > > > > >
> > > > > > at
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.getRowLockInternal(HRegion.java:5051)
> > > > > >
> > > > > > at
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.doMiniBatchMutation(HRegion.java:2944)
> > > > > >
> > > > > > at
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2801)
> > > > > >
> > > > > > at
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2743)
> > > > > >
> > > > > > at
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.RSRpcServices.doBatchOp(RSRpcServices.java:692)
> > > > > >
> > > > > > at
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.RSRpcServices.doNonAtomicRegionMutation(RSRpcServices.java:654)
> > > > > >
> > > > > > at
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.RSRpcServices.multi(RSRpcServices.java:2031)
> > > > > >
> > > > > > at
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:32213)
> > > > > >
> > > > > > at
> org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2114)
> > > > > >
> > > > > > at
> org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:101)
> > > > > >
> > > > > > at
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:130)
> > > > > >
> > > > > > at
> > > org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:107)
> > > > > >
> > > > > > at java.lang.Thread.run(Thread.java:745)
> > > > > >
> > > > > > On Wed, Jun 22, 2016 at 3:50 PM, Heng Chen <
> > heng.chen.1...@gmail.com
> > > >
> > > > > > wrote:
> > > > > >
> > > > > > > Could you paste the whole jstack and relates rs log? It seems
> > row
> > > > > write
> > > > > > > lock was occupied by some thread. Need more information to
> find
> > > it.
> > > > > > >
> > > > > > > 2016-06-22 13:48 GMT+08:00 vishnu rao <jaihind...@gmail.com>:
> > > > > > >
> > > > > > > > need some help. this has happened for 2 of my servers
> > > > > > > > -------------
> > > > > > > >
> > > > > > > > *[B.defaultRpcServer.handler=2,queue=2,port=16020]
> > > > > > regionserver.HRegion:
> > > > > > > > Failed getting lock in batch put,
> > > > > > > > row=a\xF7\x1D\xCBdR\xBC\xEC_\x18D>\xA2\xD0\x95\xFF*
> > > > > > > >
> > > > > > > > *java.io.IOException: Timed out waiting for lock for row:
> > > > > > > > a\xF7\x1D\xCBdR\xBC\xEC_\x18D>\xA2\xD0\x95\xFF*
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.getRowLockInternal(HRegion.java:5051)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.doMiniBatchMutation(HRegion.java:2944)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2801)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2743)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.RSRpcServices.doBatchOp(RSRpcServices.java:692)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.RSRpcServices.doNonAtomicRegionMutation(RSRpcServices.java:654)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.regionserver.RSRpcServices.multi(RSRpcServices.java:2031)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:32213)
> > > > > > > >
> > > > > > > > at
> > > org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2114)
> > > > > > > >
> > > > > > > > at
> > > org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:101)
> > > > > > > >
> > > > > > > > at
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:130)
> > > > > > > >
> > > > > > > > at
> > > > > org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:107)
> > > > > > > >
> > > > > > > > at java.lang.Thread.run(Thread.java:745)
> > > > > > > >
> > > > > > > > --
> > > > > > > > with regards,
> > > > > > > > ch Vishnu
> > > > > > > > mash213.wordpress.com
> > > > > > > > doodle-vishnu.blogspot.in
> > > > > > > >
> > > > > > >
> > > > > >
> > > > > >
> > > > > >
> > > > > > --
> > > > > > with regards,
> > > > > > ch Vishnu
> > > > > > mash213.wordpress.com
> > > > > > doodle-vishnu.blogspot.in
> > > > > >
> > > > >
> > > >
> > > >
> > > >
> > > > --
> > > > with regards,
> > > > ch Vishnu
> > > > mash213.wordpress.com
> > > > doodle-vishnu.blogspot.in
> > > >
> > >
> >
> >
> >
> > --
> > with regards,
> > ch Vishnu
> > mash213.wordpress.com
> > doodle-vishnu.blogspot.in
> >
>
--
with regards,
ch Vishnu
mash213.wordpress.com
doodle-vishnu.blogspot.in
