Which hadoop release are you using ?
In FSOutputSummer.java, I see the following around line 106:
checkClosed();
if (off < 0 || len < 0 || off > b.length - len) {
throw new ArrayIndexOutOfBoundsException();
You didn't get ArrayIndexOutOfBoundsException - maybe b was null ?
On Thu, Jul 6, 2017 at 2:08 PM, anil gupta <anilgupt...@gmail.com> wrote:
> Hey Ted,
>
> This is what i see in one of region server log(NPE at the bottom):
> 2017-07-06 19:07:07,778 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 155739ms
> 2017-07-06 19:07:17,853 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 132731ms
> 2017-07-06 19:07:28,038 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 4316ms
> 2017-07-06 19:07:37,819 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 190960ms
> 2017-07-06 19:07:47,767 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 41231ms
> 2017-07-06 19:07:57,767 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 222748ms
> 2017-07-06 19:08:07,973 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 245966ms
> 2017-07-06 19:08:18,669 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 76257ms
> 2017-07-06 19:08:28,029 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 78310ms
> 2017-07-06 19:08:38,459 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 127828ms
> 2017-07-06 19:08:48,527 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 38647ms
> 2017-07-06 19:08:58,554 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 185493ms
> 2017-07-06 19:09:07,779 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 245608ms
> 2017-07-06 19:09:17,767 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 284400ms
> 2017-07-06 19:09:27,768 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 271921ms
> 2017-07-06 19:09:38,380 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 205397ms
> 2017-07-06 19:09:43,518 INFO [MemStoreFlusher.1] regionserver.HRegion:
> Flushing 1/1 column families, memstore=102.57 KB
> 2017-07-06 19:09:43,541 INFO [MemStoreFlusher.1]
> regionserver.DefaultStoreFlusher: Flushed, sequenceid=163, memsize=102.6
> K,
> hasBloomFilter=true, into tmp file
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/data/default/SYSTEM.CATALOG/a47ffa359aa4588f5f360790ac8e45
> 61/.tmp/80386bf477b648d1a7edbbb271601e96
> 2017-07-06 19:09:43,546 INFO [MemStoreFlusher.1]
> regionserver.StoreFile$Reader: Loaded Delete Family Bloom
> (CompoundBloomFilter) metadata for 80386bf477b648d1a7edbbb271601e96
> 2017-07-06 19:09:43,552 INFO [MemStoreFlusher.1]
> regionserver.StoreFile$Reader: Loaded Delete Family Bloom
> (CompoundBloomFilter) metadata for 80386bf477b648d1a7edbbb271601e96
> 2017-07-06 19:09:43,552 INFO [MemStoreFlusher.1] regionserver.HStore:
> Added
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/data/default/SYSTEM.CATALOG/a47ffa359aa4588f5f360790ac8e4561/0/
> 80386bf477b648d1a7edbbb271601e96,
> entries=552, sequenceid=163, filesize=11.4 K
> 2017-07-06 19:09:43,553 INFO [MemStoreFlusher.1] regionserver.HRegion:
> Finished memstore flush of ~102.57 KB/105030, currentsize=0 B/0 for region
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. in 35ms,
> sequenceid=163, compaction requested=false
> 2017-07-06 19:11:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=4799, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:11:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=65019,
> hits=64759, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.60%,
> cachingAccesses=65019, cachingHits=64759, cachingHitsRatio=99.60%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:11:25,155 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:11:25,156 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:11:25,156 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:11:25,656 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:11:25,657 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:11:25,659 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:11:25,659 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:16:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=4829, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:16:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=65379,
> hits=65119, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.60%,
> cachingAccesses=65379, cachingHits=65119, cachingHitsRatio=99.60%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:16:25,155 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:16:25,158 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:16:25,158 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:16:25,658 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:16:25,661 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:16:25,662 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:16:25,662 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:21:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=4859, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:21:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=65739,
> hits=65479, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.60%,
> cachingAccesses=65739, cachingHits=65479, cachingHitsRatio=99.60%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:21:25,155 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:21:25,156 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:21:25,156 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:21:25,656 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:21:25,658 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:21:25,660 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:21:25,660 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:26:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=4889, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:26:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=66099,
> hits=65839, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.61%,
> cachingAccesses=66099, cachingHits=65839, cachingHitsRatio=99.61%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:26:25,155 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:26:25,158 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:26:25,158 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:26:25,659 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:26:25,660 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:26:25,663 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:26:25,663 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:31:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=4919, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:31:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=66459,
> hits=66199, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.61%,
> cachingAccesses=66459, cachingHits=66199, cachingHitsRatio=99.61%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:31:25,155 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:31:25,158 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:31:25,158 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:31:25,659 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:31:25,660 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:31:25,661 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:31:25,661 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:31:40,742 INFO
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Rolled WAL
> /user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499365900659
> with entries=8, filesize=12.99 KB; new WAL
> /user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499369500724
> 2017-07-06 19:31:40,742 INFO
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Archiving
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499362300596
> to
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/oldWALs/ip-10-74-5-153.us-west-2.compute.internal%2C16020%
> 2C1499320260501.default.1499362300596
> 2017-07-06 19:31:40,745 INFO
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Archiving
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499365900659
> to
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/oldWALs/ip-10-74-5-153.us-west-2.compute.internal%2C16020%
> 2C1499320260501.default.1499365900659
> 2017-07-06 19:36:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=4949, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:36:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=66819,
> hits=66559, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.61%,
> cachingAccesses=66819, cachingHits=66559, cachingHitsRatio=99.61%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:36:25,155 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:36:25,158 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:36:25,158 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:36:25,659 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:36:25,661 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:36:25,663 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:36:25,663 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:41:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=4979, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:41:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=67179,
> hits=66919, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.61%,
> cachingAccesses=67179, cachingHits=66919, cachingHitsRatio=99.61%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:41:25,155 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:41:25,156 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:41:25,156 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:41:25,657 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:41:25,658 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:41:25,660 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:41:25,660 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:46:02,141 INFO [LruBlockCacheStatsExecutor]
> hfile.LruBlockCache: totalSize=4.93 MB, freeSize=4.67 GB, max=4.67 GB,
> blockCount=2, accesses=14931, hits=14931, hitRatio=100.00%, ,
> cachingAccesses=14931, cachingHits=14931, cachingHitsRatio=100.00%,
> evictions=5009, evicted=0, evictedPerRun=0.0
> 2017-07-06 19:46:07,418 INFO [BucketCacheStatsExecutor]
> bucket.BucketCache: failedBlockAdditions=0, totalSize=11.75 GB,
> freeSize=11.74 GB, usedSize=8.18 MB, cacheSize=7.29 MB, accesses=67539,
> hits=67279, IOhitsPerSecond=1, IOTimePerHit=0.00, hitRatio=99.62%,
> cachingAccesses=67539, cachingHits=67279, cachingHitsRatio=99.62%,
> evictions=0, evicted=0, evictedPerRun=NaN
> 2017-07-06 19:46:25,156 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Stopping HBase metrics system...
> 2017-07-06 19:46:25,158 INFO [ganglia] impl.MetricsSinkAdapter: ganglia
> thread interrupted.
> 2017-07-06 19:46:25,158 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system stopped.
> 2017-07-06 19:46:25,659 INFO [HBase-Metrics2-1] impl.MetricsConfig: loaded
> properties from hadoop-metrics2-hbase.properties
> 2017-07-06 19:46:25,660 INFO [HBase-Metrics2-1] impl.MetricsSinkAdapter:
> Sink ganglia started
> 2017-07-06 19:46:25,662 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> Scheduled snapshot period at 155 second(s).
> 2017-07-06 19:46:25,662 INFO [HBase-Metrics2-1] impl.MetricsSystemImpl:
> HBase metrics system started
> 2017-07-06 19:48:30,412 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x3da2857f
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:30,412 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x3da2857f0x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:30,414 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:30,414 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:30,415 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cd2, negotiated timeout = 40000
> 2017-07-06 19:48:30,426 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cd2
> 2017-07-06 19:48:30,427 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cd2 closed
> 2017-07-06 19:48:30,427 INFO
> [B.defaultRpcServer.handler=175,queue=15,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cd2
> 2017-07-06 19:48:30,483 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x41f2d6a0
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:30,483 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x41f2d6a00x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:30,484 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:30,485 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:30,486 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cd3, negotiated timeout = 40000
> 2017-07-06 19:48:30,493 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cd3
> 2017-07-06 19:48:30,493 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cd3 closed
> 2017-07-06 19:48:30,493 INFO
> [B.defaultRpcServer.handler=64,queue=4,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cd3
> 2017-07-06 19:48:30,520 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x2765c233
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:30,520 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x2765c2330x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:30,522 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:30,523 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:30,524 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cd4, negotiated timeout = 40000
> 2017-07-06 19:48:30,529 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cd4
> 2017-07-06 19:48:30,530 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cd4 closed
> 2017-07-06 19:48:30,530 INFO
> [B.defaultRpcServer.handler=53,queue=13,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cd4
> 2017-07-06 19:48:30,558 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x31d0fcd8
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:30,558 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x31d0fcd80x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:30,559 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:30,559 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:30,560 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cd5, negotiated timeout = 40000
> 2017-07-06 19:48:30,565 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cd5
> 2017-07-06 19:48:30,566 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cd5 closed
> 2017-07-06 19:48:30,566 INFO
> [B.defaultRpcServer.handler=112,queue=12,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cd5
> 2017-07-06 19:48:30,594 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x336d2534
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:30,594 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x336d25340x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:30,596 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:30,596 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:30,597 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cd6, negotiated timeout = 40000
> 2017-07-06 19:48:30,603 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cd6
> 2017-07-06 19:48:30,604 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cd6 closed
> 2017-07-06 19:48:30,604 INFO
> [B.defaultRpcServer.handler=12,queue=12,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cd6
> 2017-07-06 19:48:36,166 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x7afe923b
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:36,166 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x7afe923b0x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:36,167 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:36,168 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:36,168 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cd8, negotiated timeout = 40000
> 2017-07-06 19:48:36,179 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cd8
> 2017-07-06 19:48:36,180 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cd8 closed
> 2017-07-06 19:48:36,180 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cd8
> 2017-07-06 19:48:36,191 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x553c739a
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:36,191 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x553c739a0x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:36,193 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:36,194 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:36,195 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cd9, negotiated timeout = 40000
> 2017-07-06 19:48:36,202 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cd9
> 2017-07-06 19:48:36,203 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cd9 closed
> 2017-07-06 19:48:36,203 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cd9
> 2017-07-06 19:48:36,214 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020]
> zookeeper.RecoverableZooKeeper: Process identifier=hconnection-0x7f2df76f
> connecting to ZooKeeper
> ensemble=ip-10-74-31-169.us-west-2.compute.internal:2181
> 2017-07-06 19:48:36,214 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020] zookeeper.ZooKeeper:
> Initiating client connection,
> connectString=ip-10-74-31-169.us-west-2.compute.internal:2181
> sessionTimeout=90000 watcher=hconnection-0x7f2df76f0x0,
> quorum=ip-10-74-31-169.us-west-2.compute.internal:2181, baseZNode=/hbase
> 2017-07-06 19:48:36,215 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2017-07-06 19:48:36,216 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, initiating
> session
> 2017-07-06 19:48:36,216 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-
> SendThread(ip-10-74-31-169.us-west-2.compute.internal:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> ip-10-74-31-169.us-west-2.compute.internal/10.74.31.169:2181, sessionid =
> 0x15d150266d00cda, negotiated timeout = 40000
> 2017-07-06 19:48:36,222 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020]
> client.ConnectionManager$HConnectionImplementation: Closing zookeeper
> sessionid=0x15d150266d00cda
> 2017-07-06 19:48:36,222 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020] zookeeper.ZooKeeper:
> Session: 0x15d150266d00cda closed
> 2017-07-06 19:48:36,225 INFO
> [B.defaultRpcServer.handler=172,queue=12,port=16020-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x15d150266d00cda
> 2017-07-06 19:48:38,085 WARN
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.append-pool1-t1]
> wal.FSHLog: Append sequenceId=7845, requesting roll of WAL
> java.lang.NullPointerException
> at org.apache.hadoop.fs.FSOutputSummer.write(FSOutputSummer.java:106)
> at
> org.apache.hadoop.fs.FSDataOutputStream$PositionCache.write(
> FSDataOutputStream.java:60)
> at java.io.DataOutputStream.write(DataOutputStream.java:107)
> at org.apache.hadoop.hbase.KeyValue.oswrite(KeyValue.java:2571)
> at org.apache.hadoop.hbase.KeyValueUtil.oswrite(KeyValueUtil.java:623)
> at
> org.apache.hadoop.hbase.regionserver.wal.WALCellCodec$
> EnsureKvEncoder.write(WALCellCodec.java:338)
> at
> org.apache.hadoop.hbase.regionserver.wal.ProtobufLogWriter.append(
> ProtobufLogWriter.java:122)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$
> RingBufferEventHandler.append(FSHLog.java:1909)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.
> onEvent(FSHLog.java:1773)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.
> onEvent(FSHLog.java:1695)
> at
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
> 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:745)
> 2017-07-06 19:48:38,097 WARN
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Failed sync-before-close but no outstanding appends; closing
> WAL: org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append
> sequenceId=7845, requesting roll of WAL
> 2017-07-06 19:48:38,102 INFO
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Rolled WAL
> /user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499369500724
> with entries=0, filesize=174 B; new WAL
> /user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499370518086
> 2017-07-06 19:48:38,102 INFO
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Archiving
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499369500724
> to
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/oldWALs/ip-10-74-5-153.us-west-2.compute.internal%2C16020%
> 2C1499320260501.default.1499369500724
> 2017-07-06 19:48:39,235 WARN
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.append-pool1-t1]
> wal.FSHLog: Append sequenceId=7846, requesting roll of WAL
> java.lang.NullPointerException
> at org.apache.hadoop.fs.FSOutputSummer.write(FSOutputSummer.java:106)
> at
> org.apache.hadoop.fs.FSDataOutputStream$PositionCache.write(
> FSDataOutputStream.java:60)
> at java.io.DataOutputStream.write(DataOutputStream.java:107)
> at org.apache.hadoop.hbase.KeyValue.oswrite(KeyValue.java:2571)
> at org.apache.hadoop.hbase.KeyValueUtil.oswrite(KeyValueUtil.java:623)
> at
> org.apache.hadoop.hbase.regionserver.wal.WALCellCodec$
> EnsureKvEncoder.write(WALCellCodec.java:338)
> at
> org.apache.hadoop.hbase.regionserver.wal.ProtobufLogWriter.append(
> ProtobufLogWriter.java:122)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$
> RingBufferEventHandler.append(FSHLog.java:1909)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.
> onEvent(FSHLog.java:1773)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.
> onEvent(FSHLog.java:1695)
> at
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
> 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:745)
> 2017-07-06 19:48:39,255 WARN
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Failed sync-before-close but no outstanding appends; closing
> WAL: org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append
> sequenceId=7846, requesting roll of WAL
> 2017-07-06 19:48:39,261 INFO
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Rolled WAL
> /user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499370518086
> with entries=0, filesize=174 B; new WAL
> /user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499370519235
> 2017-07-06 19:48:39,261 INFO
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.logRoller]
> wal.FSHLog: Archiving
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/WALs/ip-10-74-5-153.us-west-2.compute.
> internal,16020,1499320260501/ip-10-74-5-153.us-west-2.
> compute.internal%2C16020%2C1499320260501.default.1499370518086
> to
> hdfs://ip-10-74-31-169.us-west-2.compute.internal:8020/
> user/hbase/oldWALs/ip-10-74-5-153.us-west-2.compute.internal%2C16020%
> 2C1499320260501.default.1499370518086
> 2017-07-06 19:48:40,322 WARN
> [regionserver/ip-10-74-5-153.us-west-2.compute.internal/10.
> 74.5.153:16020.append-pool1-t1]
> wal.FSHLog: Append sequenceId=7847, requesting roll of WAL
> java.lang.NullPointerException
> at org.apache.hadoop.fs.FSOutputSummer.write(FSOutputSummer.java:106)
> at
> org.apache.hadoop.fs.FSDataOutputStream$PositionCache.write(
> FSDataOutputStream.java:60)
> at java.io.DataOutputStream.write(DataOutputStream.java:107)
> at org.apache.hadoop.hbase.KeyValue.oswrite(KeyValue.java:2571)
> at org.apache.hadoop.hbase.KeyValueUtil.oswrite(KeyValueUtil.java:623)
> at
> org.apache.hadoop.hbase.regionserver.wal.WALCellCodec$
> EnsureKvEncoder.write(WALCellCodec.java:338)
> at
> org.apache.hadoop.hbase.regionserver.wal.ProtobufLogWriter.append(
> ProtobufLogWriter.java:122)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$
> RingBufferEventHandler.append(FSHLog.java:1909)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.
> onEvent(FSHLog.java:1773)
> at
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.
> onEvent(FSHLog.java:1695)
> at
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
> 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:745)
>
> On Thu, Jul 6, 2017 at 1:55 PM, Ted Yu <yuzhih...@gmail.com> wrote:
>
> > HBASE-16960 mentioned the following :
> >
> > Caused by: java.net.SocketTimeoutException: 20000 millis timeout while
> > waiting for channel to be ready for read
> >
> > Do you see similar line in region server log ?
> >
> > Cheers
> >
> > On Thu, Jul 6, 2017 at 1:48 PM, anil gupta <anilgupt...@gmail.com>
> wrote:
> >
> > > Hi All,
> > >
> > > We are running HBase/Phoenix on EMR5.2(HBase1.2.3 and Phoenix4.7) and
> we
> > running into following exception when we are trying to load data into one
> > of our Phoenix table:
> > > 2017-07-06 19:57:57,507 INFO [hconnection-0x60e5272-shared-
> -pool2-t249]
> > org.apache.hadoop.hbase.client.AsyncProcess: #1, table=DE.CONFIG_DATA,
> > attempt=30/35 failed=38ops, last exception: org.apache.hadoop.hbase.
> > regionserver.wal.DamagedWALException: org.apache.hadoop.hbase.
> > regionserver.wal.DamagedWALException: Append sequenceId=8689, requesting
> > roll of WAL
> > > at org.apache.hadoop.hbase.regionserver.wal.FSHLog$
> > RingBufferEventHandler.append(FSHLog.java:1921)
> > > at org.apache.hadoop.hbase.regionserver.wal.FSHLog$
> > RingBufferEventHandler.onEvent(FSHLog.java:1773)
> > > at org.apache.hadoop.hbase.regionserver.wal.FSHLog$
> > RingBufferEventHandler.onEvent(FSHLog.java:1695)
> > > at com.lmax.disruptor.BatchEventProcessor.run(
> > BatchEventProcessor.java:128)
> > > 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:745)
> > >
> > > We are OK with wiping out this table and rebuilding the dataset. We
> > tried to drop the table and recreate the table but it didnt fix it.
> > > Can anyone please let us know how can we get rid of above problem? Are
> > we running into https://issues.apache.org/jira/browse/HBASE-16960?
> > >
> > >
> > > --
> > > Thanks & Regards,
> > > Anil Gupta
> > >
> >
>
>
>
> --
> Thanks & Regards,
> Anil Gupta
>
