[
https://issues.apache.org/jira/browse/HBASE-19701?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16367924#comment-16367924
]
stack commented on HBASE-19701:
-------------------------------
Bug. To be fixed. Shouldn't block beta-2 though. Moved it out.
> Close without justification following succesful open
> ----------------------------------------------------
>
> Key: HBASE-19701
> URL: https://issues.apache.org/jira/browse/HBASE-19701
> Project: HBase
> Issue Type: Bug
> Reporter: stack
> Priority: Critical
> Fix For: 2.0.0
>
>
> [~jmspaggi] conjured an interesting condition where we close a region soon
> after open WITHOUT seemingly saying why (It looks like Master is asking for
> region CLOSE but that is not clear looking at RegionServer log).
> Here is log snippet from https://pastebin.com/0r76Y6ap (in case the pastebin
> evaporates)
> {code}
> ....
> 2017-12-31 09:54:20,864 INFO
> [PostOpenDeployTasks:f49f3cbb7f3db4cf96c7eb3b0cf83869]
> regionserver.HRegionServer: Post open deploy tasks for
> TestTable,00000000000000000408944640,1505391191559.f49f3cbb7f3db4cf96c7eb3b0cf83869.
> 2017-12-31 09:54:20,870 INFO
> [StoreOpener-330f09f4a0eaf26811c320fbf1b14e70-1]
> regionserver.CompactingMemStore: Setting in-memory flush size threshold to
> 13421772 and immutable segments index to be of type CHUNK_MAP
> 2017-12-31 09:54:20,870 INFO
> [StoreOpener-330f09f4a0eaf26811c320fbf1b14e70-1] regionserver.HStore:
> Memstore class name is org.apache.hadoop.hbase.regionserver.CompactingMemStore
> 2017-12-31 09:54:20,870 INFO
> [StoreOpener-330f09f4a0eaf26811c320fbf1b14e70-1] hfile.CacheConfig: Created
> cacheConfig for info: blockCache=LruBlockCache{blockCount=0,
> currentSize=2454760, freeSize=3347745560, maxSize=3350200320,
> heapSize=2454760, minSize=3182690304, minFactor=0.95, multiSize=1591345152,
> multiFactor=0.5, singleSize=795672576, singleFactor=0.25},
> cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false,
> cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false,
> prefetchOnOpen=false
> 2017-12-31 09:54:20,872 INFO
> [StoreOpener-330f09f4a0eaf26811c320fbf1b14e70-1]
> compactions.CompactionConfiguration: size [134217728, 9223372036854775807,
> 9223372036854775807); files [3, 10); ratio 1,200000; off-peak ratio 5,000000;
> throttle point 2684354560; major period 604800000, major jitter 0,500000, min
> locality to compact 0,000000; tiered compaction: max_age 9223372036854775807,
> incoming window min 6, compaction policy for tiered window
> org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy,
> single output for minor true, compaction window factory
> org.apache.hadoop.hbase.regionserver.compactions.ExponentialCompactionWindowFactory
> 2017-12-31 09:54:20,903 INFO
> [StoreOpener-166b9c45d7724f72fd126adb4445d6ec-1]
> regionserver.CompactingMemStore: Setting in-memory flush size threshold to
> 13421772 and immutable segments index to be of type CHUNK_MAP
> 2017-12-31 09:54:20,904 INFO
> [StoreOpener-166b9c45d7724f72fd126adb4445d6ec-1] regionserver.HStore:
> Memstore class name is org.apache.hadoop.hbase.regionserver.CompactingMemStore
> 2017-12-31 09:54:20,904 INFO
> [StoreOpener-166b9c45d7724f72fd126adb4445d6ec-1] hfile.CacheConfig: Created
> cacheConfig for info: blockCache=LruBlockCache{blockCount=0,
> currentSize=2454760, freeSize=3347745560, maxSize=3350200320,
> heapSize=2454760, minSize=3182690304, minFactor=0.95, multiSize=1591345152,
> multiFactor=0.5, singleSize=795672576, singleFactor=0.25},
> cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false,
> cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false,
> prefetchOnOpen=false
> 2017-12-31 09:54:20,905 INFO
> [StoreOpener-166b9c45d7724f72fd126adb4445d6ec-1]
> compactions.CompactionConfiguration: size [134217728, 9223372036854775807,
> 9223372036854775807); files [3, 10); ratio 1,200000; off-peak ratio 5,000000;
> throttle point 2684354560; major period 604800000, major jitter 0,500000, min
> locality to compact 0,000000; tiered compaction: max_age 9223372036854775807,
> incoming window min 6, compaction policy for tiered window
> org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy,
> single output for minor true, compaction window factory
> org.apache.hadoop.hbase.regionserver.compactions.ExponentialCompactionWindowFactory
> 2017-12-31 09:54:20,929 INFO [RS_OPEN_REGION-node1:16020-1]
> regionserver.HRegion: Setting FlushNonSloppyStoresFirstPolicy for the
> region=TestTable,00000000000000000262144000,1505391191559.166b9c45d7724f72fd126adb4445d6ec.
> 2017-12-31 09:54:20,956 INFO [RS_OPEN_REGION-node1:16020-0]
> regionserver.HRegion: Setting FlushNonSloppyStoresFirstPolicy for the
> region=TestTable,00000000000000000188743680,1505391191559.330f09f4a0eaf26811c320fbf1b14e70.
> 2017-12-31 09:54:20,991 INFO [RS_OPEN_REGION-node1:16020-1]
> regionserver.HRegion: Onlined 166b9c45d7724f72fd126adb4445d6ec; next
> sequenceid=22861
> 2017-12-31 09:54:20,998 INFO
> [PostOpenDeployTasks:166b9c45d7724f72fd126adb4445d6ec]
> regionserver.HRegionServer: Post open deploy tasks for
> TestTable,00000000000000000262144000,1505391191559.166b9c45d7724f72fd126adb4445d6ec.
> 2017-12-31 09:54:21,025 INFO [RS_OPEN_REGION-node1:16020-0]
> regionserver.HRegion: Onlined 330f09f4a0eaf26811c320fbf1b14e70; next
> sequenceid=21870
> 2017-12-31 09:54:21,031 INFO
> [PostOpenDeployTasks:330f09f4a0eaf26811c320fbf1b14e70]
> regionserver.HRegionServer: Post open deploy tasks for
> TestTable,00000000000000000188743680,1505391191559.330f09f4a0eaf26811c320fbf1b14e70.
> 2017-12-31 09:54:21,036 INFO
> [StoreOpener-ba17cd27e2822b91193359a273684ac2-1]
> regionserver.CompactingMemStore: Setting in-memory flush size threshold to
> 13421772 and immutable segments index to be of type CHUNK_MAP
> 2017-12-31 09:54:21,036 INFO
> [StoreOpener-ba17cd27e2822b91193359a273684ac2-1] regionserver.HStore:
> Memstore class name is org.apache.hadoop.hbase.regionserver.CompactingMemStore
> 2017-12-31 09:54:21,036 INFO
> [StoreOpener-ba17cd27e2822b91193359a273684ac2-1] hfile.CacheConfig: Created
> cacheConfig for info: blockCache=LruBlockCache{blockCount=0,
> currentSize=2454760, freeSize=3347745560, maxSize=3350200320,
> heapSize=2454760, minSize=3182690304, minFactor=0.95, multiSize=1591345152,
> multiFactor=0.5, singleSize=795672576, singleFactor=0.25},
> cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false,
> cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false,
> prefetchOnOpen=false
> 2017-12-31 09:54:21,037 INFO
> [StoreOpener-ba17cd27e2822b91193359a273684ac2-1]
> compactions.CompactionConfiguration: size [134217728, 9223372036854775807,
> 9223372036854775807); files [3, 10); ratio 1,200000; off-peak ratio 5,000000;
> throttle point 2684354560; major period 604800000, major jitter 0,500000, min
> locality to compact 0,000000; tiered compaction: max_age 9223372036854775807,
> incoming window min 6, compaction policy for tiered window
> org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy,
> single output for minor true, compaction window factory
> org.apache.hadoop.hbase.regionserver.compactions.ExponentialCompactionWindowFactory
> 2017-12-31 09:54:21,058 INFO
> [StoreOpener-e6ad456daff7a3d4ad259eab64a61c11-1]
> regionserver.CompactingMemStore: Setting in-memory flush size threshold to
> 13421772 and immutable segments index to be of type CHUNK_MAP
> 2017-12-31 09:54:21,059 INFO
> [StoreOpener-e6ad456daff7a3d4ad259eab64a61c11-1] regionserver.HStore:
> Memstore class name is org.apache.hadoop.hbase.regionserver.CompactingMemStore
> 2017-12-31 09:54:21,059 INFO
> [StoreOpener-e6ad456daff7a3d4ad259eab64a61c11-1] hfile.CacheConfig: Created
> cacheConfig for info: blockCache=LruBlockCache{blockCount=0,
> currentSize=2454760, freeSize=3347745560, maxSize=3350200320,
> heapSize=2454760, minSize=3182690304, minFactor=0.95, multiSize=1591345152,
> multiFactor=0.5, singleSize=795672576, singleFactor=0.25},
> cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false,
> cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false,
> prefetchOnOpen=false
> 2017-12-31 09:54:21,063 INFO
> [StoreOpener-e6ad456daff7a3d4ad259eab64a61c11-1]
> compactions.CompactionConfiguration: size [134217728, 9223372036854775807,
> 9223372036854775807); files [3, 10); ratio 1,200000; off-peak ratio 5,000000;
> throttle point 2684354560; major period 604800000, major jitter 0,500000, min
> locality to compact 0,000000; tiered compaction: max_age 9223372036854775807,
> incoming window min 6, compaction policy for tiered window
> org.apache.hadoop.hbase.regionserver.compactions.ExploringCompactionPolicy,
> single output for minor true, compaction window factory
> org.apache.hadoop.hbase.regionserver.compactions.ExponentialCompactionWindowFactory
> 2017-12-31 09:54:21,150 INFO [RS_OPEN_REGION-node1:16020-2]
> regionserver.HRegion: Setting FlushNonSloppyStoresFirstPolicy for the
> region=TestTable,00000000000000000555745280,1505391191559.19d79b967c2e59cef288874533c154c8.
> 2017-12-31 09:54:21,234 INFO [RS_OPEN_REGION-node1:16020-0]
> regionserver.HRegion: Setting FlushNonSloppyStoresFirstPolicy for the
> region=TestTable,00000000000000000115343360,1505391191559.e6ad456daff7a3d4ad259eab64a61c11.
> 2017-12-31 09:54:21,258 INFO [RS_OPEN_REGION-node1:16020-2]
> regionserver.HRegion: Onlined 19d79b967c2e59cef288874533c154c8; next
> sequenceid=23352
> 2017-12-31 09:54:21,264 INFO
> [PostOpenDeployTasks:19d79b967c2e59cef288874533c154c8]
> regionserver.HRegionServer: Post open deploy tasks for
> TestTable,00000000000000000555745280,1505391191559.19d79b967c2e59cef288874533c154c8.
> 2017-12-31 09:54:21,313 INFO [RS_OPEN_REGION-node1:16020-0]
> regionserver.HRegion: Onlined e6ad456daff7a3d4ad259eab64a61c11; next
> sequenceid=21294
> 2017-12-31 09:54:21,321 INFO [RS_OPEN_REGION-node1:16020-1]
> regionserver.HRegion: Setting FlushNonSloppyStoresFirstPolicy for the
> region=TestTable,00000000000000000335544320,1505391191559.ba17cd27e2822b91193359a273684ac2.
> 2017-12-31 09:54:21,321 INFO
> [PostOpenDeployTasks:e6ad456daff7a3d4ad259eab64a61c11]
> regionserver.HRegionServer: Post open deploy tasks for
> TestTable,00000000000000000115343360,1505391191559.e6ad456daff7a3d4ad259eab64a61c11.
> 2017-12-31 09:54:21,380 INFO [RS_OPEN_REGION-node1:16020-1]
> regionserver.HRegion: Onlined ba17cd27e2822b91193359a273684ac2; next
> sequenceid=22282
> 2017-12-31 09:54:21,386 INFO
> [PostOpenDeployTasks:ba17cd27e2822b91193359a273684ac2]
> regionserver.HRegionServer: Post open deploy tasks for
> TestTable,00000000000000000335544320,1505391191559.ba17cd27e2822b91193359a273684ac2.
> 2017-12-31 09:54:40,649 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close 166b9c45d7724f72fd126adb4445d6ec without
> moving
> 2017-12-31 09:54:40,655 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close ba17cd27e2822b91193359a273684ac2 without
> moving
> 2017-12-31 09:54:40,680 INFO
> [StoreCloserThread-TestTable,00000000000000000335544320,1505391191559.ba17cd27e2822b91193359a273684ac2.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:40,680 INFO
> [StoreCloserThread-TestTable,00000000000000000262144000,1505391191559.166b9c45d7724f72fd126adb4445d6ec.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:40,702 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close 98025e37220dbc821f862a91d05a96ef without
> moving
> 2017-12-31 09:54:40,703 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close 19d79b967c2e59cef288874533c154c8 without
> moving
> 2017-12-31 09:54:40,707 INFO
> [StoreCloserThread-TestTable,00000000000000000482344960,1505391191559.98025e37220dbc821f862a91d05a96ef.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:40,741 INFO [RS_CLOSE_REGION-node1:16020-0]
> regionserver.HRegion: Closed
> TestTable,00000000000000000262144000,1505391191559.166b9c45d7724f72fd126adb4445d6ec.
> 2017-12-31 09:54:40,754 INFO
> [StoreCloserThread-TestTable,00000000000000000555745280,1505391191559.19d79b967c2e59cef288874533c154c8.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:40,762 INFO [RS_CLOSE_REGION-node1:16020-1]
> regionserver.HRegion: Closed
> TestTable,00000000000000000335544320,1505391191559.ba17cd27e2822b91193359a273684ac2.
> 2017-12-31 09:54:40,807 INFO [RS_CLOSE_REGION-node1:16020-2]
> regionserver.HRegion: Closed
> TestTable,00000000000000000482344960,1505391191559.98025e37220dbc821f862a91d05a96ef.
> 2017-12-31 09:54:40,839 INFO [RS_CLOSE_REGION-node1:16020-0]
> regionserver.HRegion: Closed
> TestTable,00000000000000000555745280,1505391191559.19d79b967c2e59cef288874533c154c8.
> 2017-12-31 09:54:41,102 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close f49f3cbb7f3db4cf96c7eb3b0cf83869 without
> moving
> 2017-12-31 09:54:41,105 INFO
> [StoreCloserThread-TestTable,00000000000000000408944640,1505391191559.f49f3cbb7f3db4cf96c7eb3b0cf83869.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:41,184 INFO [RS_CLOSE_REGION-node1:16020-1]
> regionserver.HRegion: Closed
> TestTable,00000000000000000408944640,1505391191559.f49f3cbb7f3db4cf96c7eb3b0cf83869.
> 2017-12-31 09:54:42,249 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close e6ad456daff7a3d4ad259eab64a61c11 without
> moving
> 2017-12-31 09:54:42,250 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close 330f09f4a0eaf26811c320fbf1b14e70 without
> moving
> 2017-12-31 09:54:42,250 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close 655b0a0608ebaecacfda2e25a7e4b0f5 without
> moving
> 2017-12-31 09:54:42,253 INFO
> [StoreCloserThread-TestTable,00000000000000000115343360,1505391191559.e6ad456daff7a3d4ad259eab64a61c11.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:42,254 INFO
> [StoreCloserThread-TestTable,00000000000000000188743680,1505391191559.330f09f4a0eaf26811c320fbf1b14e70.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:42,254 INFO
> [StoreCloserThread-TestTable,00000000000000000178257920,1505391191559.655b0a0608ebaecacfda2e25a7e4b0f5.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:42,341 INFO [RS_CLOSE_REGION-node1:16020-1]
> regionserver.HRegion: Closed
> TestTable,00000000000000000178257920,1505391191559.655b0a0608ebaecacfda2e25a7e4b0f5.
> 2017-12-31 09:54:42,360 INFO [RS_CLOSE_REGION-node1:16020-2]
> regionserver.HRegion: Closed
> TestTable,00000000000000000115343360,1505391191559.e6ad456daff7a3d4ad259eab64a61c11.
> 2017-12-31 09:54:42,361 INFO [RS_CLOSE_REGION-node1:16020-0]
> regionserver.HRegion: Closed
> TestTable,00000000000000000188743680,1505391191559.330f09f4a0eaf26811c320fbf1b14e70.
> 2017-12-31 09:54:42,412 INFO
> [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020]
> regionserver.RSRpcServices: Close 30eaa72ddc1f2706dc84c62e3222a006 without
> moving
> 2017-12-31 09:54:42,415 INFO
> [StoreCloserThread-TestTable,00000000000000000041943040,1505391191559.30eaa72ddc1f2706dc84c62e3222a006.-1]
> regionserver.HStore: Closed info
> 2017-12-31 09:54:42,495 INFO [RS_CLOSE_REGION-node1:16020-1]
> regionserver.HRegion: Closed
> TestTable,00000000000000000041943040,1505391191559.30eaa72ddc1f2706dc84c62e3222a006.
> 2017-12-31 09:54:53,069 INFO [ReadOnlyZKClient] zookeeper.ReadOnlyZKClient:
> 0x1df82317 no activities for 60000 ms, close active connection. Will
> reconnect next time when there are new requests.
> 2017-12-31 09:54:53,088 INFO [ReadOnlyZKClient] zookeeper.ZooKeeper:
> Session: 0x160a94d45ab0122 closed
> 2017-12-31 09:54:53,088 INFO [ReadOnlyZKClient-EventThread]
> zookeeper.ClientCnxn: EventThread shut down for session: 0x160a94d45ab0122
> ...
> {code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
