phoenix-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Josh Mahonin <jmaho...@gmail.com>
Subject Re: Exception ERROR 201 (22000): Illegal data. Expected length of at least 8 bytes, but had 4
Date Wed, 05 Jul 2017 13:35:25 GMT
Hi,

>From the logs you attached, it appears that you're getting the exception on
the following query:

SELECT trid, tid, frtp, frno, gzid, ontm, onty, onlt, onln,
oftm, ofty, oflt, ofln, onwk, onhr, wday, dist, drtn, delf, sntf,
cdtm, udtm FROM  trp WHERE  tid = ? AND delf = FALSE ORDER BY oftm
DESC NULLS LAST FETCH FIRST 1 ROW ONLY

Are you able to reproduce this issue by executing that query directly?
Given a snippet of your stack trace, I'm not sure if Spark is the culprit
here, so it'd be nice to try identify the root cause (or maybe correlate it
to an existing JIRA ticket)

...
Caused by: java.sql.SQLException: ERROR 201 (22000): Illegal data.
ERROR 201 (22000): ERROR 201 (22000): Illegal data. Expected length of
at least 8 bytes, but had 4
TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00,
1499228698442.4f312a19bfdc624776516228c9c4f2d5.
 at org.apache.phoenix.exception.SQLExceptionCode$Factory$1.
newException(SQLExceptionCode.java:464)
 at org.apache.phoenix.exception.SQLExceptionInfo.buildException(
SQLExceptionInfo.java:150)
 at org.apache.phoenix.util.ServerUtil.parseRemoteException(
ServerUtil.java:134)
 at org.apache.phoenix.util.ServerUtil.parseServerExceptionOrNull(
ServerUtil.java:123)
 at org.apache.phoenix.util.ServerUtil.parseServerException(
ServerUtil.java:109)
 at org.apache.phoenix.iterate.BaseResultIterators.getIterators(
BaseResultIterators.java:755)
 at org.apache.phoenix.iterate.BaseResultIterators.getIterators(
BaseResultIterators.java:699)
 at org.apache.phoenix.iterate.MergeSortResultIterator.getMinHeap(
MergeSortResultIterator.java:72)
 at org.apache.phoenix.iterate.MergeSortResultIterator.minIterator(
MergeSortResultIterator.java:93)
 at org.apache.phoenix.iterate.MergeSortResultIterator.next(
MergeSortResultIterator.java:58)
 at org.apache.phoenix.iterate.MergeSortTopNResultIterator.next(
MergeSortTopNResultIterator.java:95)
 at org.apache.phoenix.jdbc.PhoenixResultSet.next(PhoenixResultSet.java:778)
...

Also, are you able to post your CREATE TABLE DDL for the 'trp' table you're
querying?

Thanks,

Josh

On Wed, Jul 5, 2017 at 1:24 AM, Takashi Sasaki <tsasaki609@gmail.com> wrote:

> Hi,
>
> I'm using Phoenix4.9.0/HBase1.3.0 with Spark2.1.1 on AWS EMR 5.6.0.
>
> When one side uses Spark Streaming to write a lot of data and the
> other side uses Spark to read data,
> I encounter several similar exceptions.
>
> 17/07/05 04:33:47 ERROR Executor: Exception in task 83.0 in stage
> 166.0 (TID 95211)
> org.apache.ibatis.exceptions.PersistenceException:
> ### Error querying database.  Cause: java.sql.SQLException: ERROR 201
> (22000): Illegal data. ERROR 201 (22000): ERROR 201 (22000): Illegal
> data. Expected length of at least 8 bytes, but had 4
> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
> ### The error may exist in agp/mapper/TripMapper.java (best guess)
> ### The error may involve agp.mapper.TripMapper.selectLast
> ### The error occurred while handling results
> ### SQL: SELECT trid, tid, frtp, frno, gzid, ontm, onty, onlt, onln,
> oftm, ofty, oflt, ofln, onwk, onhr, wday, dist, drtn, delf, sntf,
> cdtm, udtm FROM  trp WHERE  tid = ? AND delf = FALSE ORDER BY oftm
> DESC NULLS LAST FETCH FIRST 1 ROW ONLY
> ### Cause: java.sql.SQLException: ERROR 201 (22000): Illegal data.
> ERROR 201 (22000): ERROR 201 (22000): Illegal data. Expected length of
> at least 8 bytes, but had 4
> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
>  at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(
> ExceptionFactory.java:30)
>  at org.apache.ibatis.session.defaults.DefaultSqlSession.
> selectList(DefaultSqlSession.java:150)
>  at org.apache.ibatis.session.defaults.DefaultSqlSession.
> selectList(DefaultSqlSession.java:141)
>  at org.apache.ibatis.session.defaults.DefaultSqlSession.
> selectOne(DefaultSqlSession.java:77)
>  at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:82)
>  at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)
>  at com.sun.proxy.$Proxy38.selectLast(Unknown Source)
>  at agp.dao.TripDAO.selectLast(TripDAO.java:55)
>  at agp.trip.func.trip.SelectTripCondition.fixAccOnLocation(
> SelectTripCondition.java:128)
>  at agp.trip.func.trip.SelectTripCondition.call(
> SelectTripCondition.java:65)
>  at agp.trip.func.trip.SelectTripCondition.call(
> SelectTripCondition.java:25)
>  at org.apache.spark.api.java.JavaRDDLike$$anonfun$fn$1$1.
> apply(JavaRDDLike.scala:125)
>  at org.apache.spark.api.java.JavaRDDLike$$anonfun$fn$1$1.
> apply(JavaRDDLike.scala:125)
>  at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434)
>  at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440)
>  at scala.collection.Iterator$$anon$13.hasNext(Iterator.scala:461)
>  at scala.collection.Iterator$$anon$11.hasNext(Iterator.scala:408)
>  at org.apache.spark.shuffle.sort.UnsafeShuffleWriter.write(
> UnsafeShuffleWriter.java:166)
>  at org.apache.spark.scheduler.ShuffleMapTask.runTask(
> ShuffleMapTask.scala:96)
>  at org.apache.spark.scheduler.ShuffleMapTask.runTask(
> ShuffleMapTask.scala:53)
>  at org.apache.spark.scheduler.Task.run(Task.scala:99)
>  at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:322)
>  at java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1142)
>  at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
>  at java.lang.Thread.run(Thread.java:748)
> Caused by: java.sql.SQLException: ERROR 201 (22000): Illegal data.
> ERROR 201 (22000): ERROR 201 (22000): Illegal data. Expected length of
> at least 8 bytes, but had 4
> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
>  at org.apache.phoenix.exception.SQLExceptionCode$Factory$1.
> newException(SQLExceptionCode.java:464)
>  at org.apache.phoenix.exception.SQLExceptionInfo.buildException(
> SQLExceptionInfo.java:150)
>  at org.apache.phoenix.util.ServerUtil.parseRemoteException(
> ServerUtil.java:134)
>  at org.apache.phoenix.util.ServerUtil.parseServerExceptionOrNull(
> ServerUtil.java:123)
>  at org.apache.phoenix.util.ServerUtil.parseServerException(
> ServerUtil.java:109)
>  at org.apache.phoenix.iterate.BaseResultIterators.getIterators(
> BaseResultIterators.java:755)
>  at org.apache.phoenix.iterate.BaseResultIterators.getIterators(
> BaseResultIterators.java:699)
>  at org.apache.phoenix.iterate.MergeSortResultIterator.getMinHeap(
> MergeSortResultIterator.java:72)
>  at org.apache.phoenix.iterate.MergeSortResultIterator.minIterator(
> MergeSortResultIterator.java:93)
>  at org.apache.phoenix.iterate.MergeSortResultIterator.next(
> MergeSortResultIterator.java:58)
>  at org.apache.phoenix.iterate.MergeSortTopNResultIterator.next(
> MergeSortTopNResultIterator.java:95)
>  at org.apache.phoenix.jdbc.PhoenixResultSet.next(
> PhoenixResultSet.java:778)
>  at sun.reflect.GeneratedMethodAccessor37.invoke(Unknown Source)
>  at sun.reflect.DelegatingMethodAccessorImpl.invoke(
> DelegatingMethodAccessorImpl.java:43)
>  at java.lang.reflect.Method.invoke(Method.java:498)
>  at org.apache.ibatis.logging.jdbc.ResultSetLogger.invoke(
> ResultSetLogger.java:68)
>  at com.sun.proxy.$Proxy37.next(Unknown Source)
>  at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.
> handleRowValuesForSimpleResultMap(DefaultResultSetHandler.java:345)
>  at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.
> handleRowValues(DefaultResultSetHandler.java:322)
>  at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.
> handleResultSet(DefaultResultSetHandler.java:295)
>  at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.
> handleResultSets(DefaultResultSetHandler.java:192)
>  at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(
> PreparedStatementHandler.java:64)
>  at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(
> RoutingStatementHandler.java:79)
>  at org.apache.ibatis.executor.SimpleExecutor.doQuery(
> SimpleExecutor.java:63)
>  at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(
> BaseExecutor.java:324)
>  at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
>  at org.apache.ibatis.executor.CachingExecutor.query(
> CachingExecutor.java:109)
>  at org.apache.ibatis.executor.CachingExecutor.query(
> CachingExecutor.java:83)
>  at org.apache.ibatis.session.defaults.DefaultSqlSession.
> selectList(DefaultSqlSession.java:148)
>  ... 23 more
> Caused by: org.apache.hadoop.hbase.DoNotRetryIOException:
> org.apache.hadoop.hbase.DoNotRetryIOException: ERROR 201 (22000):
> ERROR 201 (22000): Illegal data. Expected length of at least 8 bytes,
> but had 4 TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
>  at org.apache.phoenix.util.ServerUtil.createIOException(
> ServerUtil.java:81)
>  at org.apache.phoenix.util.ServerUtil.throwIOException(
> ServerUtil.java:55)
>  at org.apache.phoenix.coprocessor.ScanRegionObserver.getTopNScanner(
> ScanRegionObserver.java:328)
>  at org.apache.phoenix.coprocessor.ScanRegionObserver.doPostScannerOpen(
> ScanRegionObserver.java:241)
>  at org.apache.phoenix.coprocessor.BaseScannerRegionObserver$
> RegionScannerHolder.overrideDelegate(BaseScannerRegionObserver.java:215)
>  at org.apache.phoenix.coprocessor.BaseScannerRegionObserver$
> RegionScannerHolder.nextRaw(BaseScannerRegionObserver.java:260)
>  at org.apache.hadoop.hbase.regionserver.RSRpcServices.
> scan(RSRpcServices.java:2633)
>  at org.apache.hadoop.hbase.regionserver.RSRpcServices.
> scan(RSRpcServices.java:2837)
>  at org.apache.hadoop.hbase.protobuf.generated.
> ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:34950)
>  at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2339)
>  at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:123)
>  at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(
> RpcExecutor.java:188)
>  at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(
> RpcExecutor.java:168)
> Caused by: java.sql.SQLException: ERROR 201 (22000): Illegal data.
> Expected length of at least 8 bytes, but had 4
>  at org.apache.phoenix.exception.SQLExceptionCode$Factory$1.
> newException(SQLExceptionCode.java:464)
>  at org.apache.phoenix.exception.SQLExceptionInfo.buildException(
> SQLExceptionInfo.java:150)
>  at org.apache.phoenix.util.ServerUtil.parseRemoteException(
> ServerUtil.java:134)
>  at org.apache.phoenix.util.ServerUtil.parseServerExceptionOrNull(
> ServerUtil.java:123)
>  at org.apache.phoenix.util.ServerUtil.parseServerException(
> ServerUtil.java:109)
>  at org.apache.phoenix.iterate.RegionScannerResultIterator.next(
> RegionScannerResultIterator.java:61)
>  at org.apache.phoenix.iterate.OrderedResultIterator.getResultIterator(
> OrderedResultIterator.java:254)
>  at org.apache.phoenix.iterate.OrderedResultIterator.next(
> OrderedResultIterator.java:198)
>  at org.apache.phoenix.coprocessor.ScanRegionObserver.getTopNScanner(
> ScanRegionObserver.java:323)
>  ... 10 more
> Caused by: java.sql.SQLException: ERROR 201 (22000): Illegal data.
> Expected length of at least 8 bytes, but had 4
>  at org.apache.phoenix.exception.SQLExceptionCode$Factory$1.
> newException(SQLExceptionCode.java:464)
>  at org.apache.phoenix.exception.SQLExceptionInfo.buildException(
> SQLExceptionInfo.java:150)
>  at org.apache.phoenix.schema.KeyValueSchema.next(KeyValueSchema.java:213)
>  at org.apache.phoenix.expression.ProjectedColumnExpression.evaluate(
> ProjectedColumnExpression.java:115)
>  at org.apache.phoenix.schema.KeyValueSchema.toBytes(
> KeyValueSchema.java:112)
>  at org.apache.phoenix.execute.TupleProjector.projectResults(
> TupleProjector.java:245)
>  at org.apache.phoenix.coprocessor.BaseScannerRegionObserver$1.nextRaw(
> BaseScannerRegionObserver.java:441)
>  at org.apache.phoenix.iterate.RegionScannerResultIterator.next(
> RegionScannerResultIterator.java:50)
>  ... 13 more
>  at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
>  at sun.reflect.NativeConstructorAccessorImpl.newInstance(
> NativeConstructorAccessorImpl.java:62)
>  at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(
> DelegatingConstructorAccessorImpl.java:45)
>  at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
>  at org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(
> RemoteExceptionHandler.java:97)
>  at org.apache.hadoop.hbase.client.ScannerCallable.call(
> ScannerCallable.java:272)
>  at org.apache.hadoop.hbase.client.ScannerCallable.call(
> ScannerCallable.java:64)
>  at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithoutRetries(
> RpcRetryingCaller.java:200)
>  at org.apache.hadoop.hbase.client.ScannerCallableWithReplicas$
> RetryingRPC.call(ScannerCallableWithReplicas.java:360)
>  at org.apache.hadoop.hbase.client.ScannerCallableWithReplicas$
> RetryingRPC.call(ScannerCallableWithReplicas.java:334)
>  at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(
> RpcRetryingCaller.java:126)
>  at org.apache.hadoop.hbase.client.ResultBoundedCompletionService
> $QueueingFuture.run(ResultBoundedCompletionService.java:65)
>  ... 3 more
>
> HBase Region Server Logs below,
> 1.
> 2017-07-05 04:33:41,181 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
> 2017-07-05 04:33:50,929 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 2.
> 2017-07-05 04:32:52,087 INFO  [sync.2] wal.FSHLog: Slow sync cost: 104
> ms, current pipeline:
> [DatanodeInfoWithStorage[172.31.10.147:50010,DS-289c3237-
> 9ec2-4abc-9fe8-e114fde75483,DISK],
> DatanodeInfoWithStorage[172.31.8.18:50010,DS-5887519a-
> 6424-4bf9-9c09-35d9b13b5b1d,DISK],
> DatanodeInfoWithStorage[172.31.10.188:50010,DS-0c7f1e59-
> 1719-4f5d-a400-79276b4469d1,DISK]]
> 2017-07-05 04:34:31,791 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 3.
> 2017-07-05 04:32:54,447 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=80.00 GB, usedSize=2.87 MB, cacheSize=1.87 MB, accesses=802,
> hits=261, IOhitsPerSecond=0, IOTimePerHit=0.11, hitRatio=32.54%,
> cachingAccesses=372, cachingHits=196, cachingHitsRatio=52.69%,
> evictions=0, evicted=65, evictedPerRun=Infinity
> 2017-07-05 04:34:18,621 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 4.
> 2017-07-05 04:33:41,653 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
> 2017-07-05 04:33:50,601 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 5.
> 2017-07-05 04:32:04,566 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=80.00 GB, usedSize=2.82 MB, cacheSize=1.85 MB, accesses=300,
> hits=114, IOhitsPerSecond=0, IOTimePerHit=0.11, hitRatio=38.00%,
> cachingAccesses=203, cachingHits=114, cachingHitsRatio=56.16%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-05 04:33:41,167 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 6.
> 2017-07-05 04:31:52,910 INFO
> [ip-172-31-11-39.ap-northeast-1.compute.internal,16020,
> 1499227300627-index-writer--pool30-t13]
> regionserver.HRegion: writing data to region
> TRB,\x0C\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00,1499228749864.f0fade12881d6c99e9674639c90acad1.
> with WAL disabled. Data may be lost in the event of a crash.
> 2017-07-05 04:32:04,504 INFO  [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=11.17 MB, freeSize=10.56 GB, max=10.57
> GB, blockCount=2, accesses=49007, hits=49007, hitRatio=100.00%, ,
> cachingAccesses=49007, cachingHits=49007, cachingHitsRatio=100.00%,
> evictions=179, evicted=0, evictedPerRun=0.0
> 2017-07-05 04:32:04,581 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=79.99 GB, usedSize=5.59 MB, cacheSize=3.66 MB, accesses=599,
> hits=218, IOhitsPerSecond=0, IOTimePerHit=0.09, hitRatio=36.39%,
> cachingAccesses=402, cachingHits=218, cachingHitsRatio=54.23%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-05 04:33:46,020 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 7.
> 2017-07-05 04:31:53,027 INFO
> [ip-172-31-12-156.ap-northeast-1.compute.internal,
> 16020,1499227465864-index-writer--pool26-t15]
> regionserver.HRegion: writing data to region
> TRB,\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00,1499228749864.31b5cfcc09891813241932c46e2e6d5b.
> with WAL disabled. Data may be lost in the event of a crash.
> 2017-07-05 04:34:10,233 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
> 2017-07-05 04:34:29,590 INFO  [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=11.17 MB, freeSize=10.56 GB, max=10.57
> GB, blockCount=2, accesses=27170, hits=27170, hitRatio=100.00%, ,
> cachingAccesses=27170, cachingHits=27170, cachingHitsRatio=100.00%,
> evictions=179, evicted=0, evictedPerRun=0.0
> 2017-07-05 04:34:29,643 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=80.00 GB, usedSize=2.90 MB, cacheSize=1.90 MB, accesses=295,
> hits=98, IOhitsPerSecond=0, IOTimePerHit=NaN, hitRatio=33.22%,
> cachingAccesses=200, cachingHits=98, cachingHitsRatio=49.00%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-05 04:35:13,274 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 8.
> 2017-07-05 04:27:41,202 ERROR
> [RpcServer.FifoWFPBQ.default.handler=29,queue=2,port=16020]
> coprocessor.MetaDataEndpointImpl: getTable failed
> org.apache.hadoop.hbase.NotServingRegionException:
> SYSTEM.CATALOG,,1499216017494.3bbe2fb5b186285a9555b45c87684cc7. is
> closing
>  at org.apache.hadoop.hbase.regionserver.HRegion.
> startRegionOperation(HRegion.java:8291)
>  at org.apache.hadoop.hbase.regionserver.HRegion.
> getScanner(HRegion.java:2645)
>  at org.apache.hadoop.hbase.regionserver.HRegion.
> getScanner(HRegion.java:2640)
>  at org.apache.hadoop.hbase.regionserver.HRegion.
> getScanner(HRegion.java:2634)
>  at org.apache.phoenix.coprocessor.MetaDataEndpointImpl.buildTable(
> MetaDataEndpointImpl.java:533)
>  at org.apache.phoenix.coprocessor.MetaDataEndpointImpl.doGetTable(
> MetaDataEndpointImpl.java:2939)
>  at org.apache.phoenix.coprocessor.MetaDataEndpointImpl.doGetTable(
> MetaDataEndpointImpl.java:2884)
>  at org.apache.phoenix.coprocessor.MetaDataEndpointImpl.getTable(
> MetaDataEndpointImpl.java:492)
>  at org.apache.phoenix.coprocessor.generated.MetaDataProtos$
> MetaDataService.callMethod(MetaDataProtos.java:16267)
>  at org.apache.hadoop.hbase.regionserver.HRegion.
> execService(HRegion.java:8095)
>  at org.apache.hadoop.hbase.regionserver.RSRpcServices.
> execServiceOnRegion(RSRpcServices.java:2072)
>  at org.apache.hadoop.hbase.regionserver.RSRpcServices.
> execService(RSRpcServices.java:2054)
>  at org.apache.hadoop.hbase.protobuf.generated.
> ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:34954)
>  at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2339)
>  at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:123)
>  at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(
> RpcExecutor.java:188)
>  at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(
> RpcExecutor.java:168)
> 2017-07-05 04:31:53,017 INFO
> [ip-172-31-14-56.ap-northeast-1.compute.internal,16020,
> 1499227310987-index-writer--pool43-t18]
> regionserver.HRegion: writing data to region
> TRB,\x07\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00,1499228749864.c93f2a12e912e9501f0801e9cb73f75c.
> with WAL disabled. Data may be lost in the event of a crash.
> 2017-07-05 04:32:04,571 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=80.00 GB, usedSize=3.01 MB, cacheSize=1.97 MB, accesses=1077,
> hits=881, IOhitsPerSecond=0, IOTimePerHit=0.16, hitRatio=81.80%,
> cachingAccesses=980, cachingHits=881, cachingHitsRatio=89.90%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-05 04:36:34,114 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 9.
> 2017-07-05 04:31:52,915 INFO
> [ip-172-31-3-154.ap-northeast-1.compute.internal,16020,
> 1499227309930-index-writer--pool3-t13]
> regionserver.HRegion: writing data to region
> TRB,\x0D\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00,1499228749864.9eca4d9d19a712533aa240853173c816.
> with WAL disabled. Data may be lost in the event of a crash.
> 2017-07-05 04:32:04,506 INFO  [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=11.14 MB, freeSize=10.56 GB, max=10.57
> GB, blockCount=4, accesses=26651, hits=26651, hitRatio=100.00%, ,
> cachingAccesses=26651, cachingHits=26651, cachingHitsRatio=100.00%,
> evictions=179, evicted=0, evictedPerRun=0.0
> 2017-07-05 04:32:04,556 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=80.00 GB, usedSize=2.85 MB, cacheSize=1.85 MB, accesses=334,
> hits=134, IOhitsPerSecond=0, IOTimePerHit=0.15, hitRatio=40.12%,
> cachingAccesses=239, cachingHits=134, cachingHitsRatio=56.07%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-05 04:33:33,010 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
> 2017-07-05 04:33:40,823 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 10.
> 2017-07-05 04:31:53,653 INFO
> [ip-172-31-7-66.ap-northeast-1.compute.internal,16020,
> 1499227313375-index-writer--pool38-t18]
> regionserver.HRegion: writing data to region
> TRP,\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.6706144c5be72f993a69ad9ad63005e5.
> with WAL disabled. Data may be lost in the event of a crash.
> 2017-07-05 04:32:04,504 INFO  [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=11.14 MB, freeSize=10.56 GB, max=10.57
> GB, blockCount=1, accesses=24493, hits=24493, hitRatio=100.00%, ,
> cachingAccesses=24493, cachingHits=24493, cachingHitsRatio=100.00%,
> evictions=179, evicted=0, evictedPerRun=0.0
> 2017-07-05 04:32:04,577 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=80.00 GB, usedSize=2.48 MB, cacheSize=1.62 MB, accesses=260,
> hits=81, IOhitsPerSecond=0, IOTimePerHit=0.10, hitRatio=31.15%,
> cachingAccesses=164, cachingHits=81, cachingHitsRatio=49.39%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-05 04:36:04,834 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> 11.
> 2017-07-05 04:31:53,327 INFO
> [ip-172-31-8-18.ap-northeast-1.compute.internal,16020,
> 1499227319500-index-writer--pool26-t18]
> regionserver.HRegion: writing data to region
> TRP,\x0F\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.53d87d4772b4e637b4dfd426bb11d624.
> with WAL disabled. Data may be lost in the event of a crash.
> 2017-07-05 04:32:04,505 INFO  [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=11.14 MB, freeSize=10.56 GB, max=10.57
> GB, blockCount=1, accesses=23309, hits=23309, hitRatio=100.00%, ,
> cachingAccesses=23309, cachingHits=23309, cachingHitsRatio=100.00%,
> evictions=179, evicted=0, evictedPerRun=0.0
> 2017-07-05 04:32:04,574 INFO  [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=80.00 GB,
> freeSize=80.00 GB, usedSize=2.83 MB, cacheSize=1.85 MB, accesses=330,
> hits=138, IOhitsPerSecond=0, IOTimePerHit=0.12, hitRatio=41.82%,
> cachingAccesses=232, cachingHits=138, cachingHitsRatio=59.48%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-05 04:33:58,658 WARN  [Finalizer] memory.GlobalMemoryManager:
> Orphaned chunk of 104 bytes found during finalize
>
> The TRP table is mutable which have composite parimary key, and have 5
> local indexes.
> I always upsert data from phoenix only.
>
> Phoenix Configuration is below,
> phoenix.schema.dropMetaData false
> phoenix.query.rowKeyOrderSaltedTable true
> hbase.regionserver.wal.codec
> org.apache.hadoop.hbase.regionserver.wal.IndexedWALEditCodec
> hbase.region.server.rpc.scheduler.factory.class
> org.apache.hadoop.hbase.ipc.PhoenixRpcSchedulerFactory
> phoenix.index.failure.block.write true
>
> How can i solve this?
> Please advise me if you do not mind.
>
> Thanks,
> Takashi
>

Mime
View raw message