[
https://issues.apache.org/jira/browse/HBASE-19701?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16313195#comment-16313195
]
stack commented on HBASE-19701:
-------------------------------
Some more on this -- how to repro:
Start an hbase2 configured for SNAPPY over data written by an hbase1. The
SNAPPY install should be incomplete such that cluster startup fails. Fix SNAPPY
and then restart.
Up on the dev list, on the thread "[VOTE] The first hbase-2.0.0-beta-1 Release
Candidate is available", [~jmspaggi] found that the start over a bad SNAPPY
install damaged his cluster such that he had to start over.
The startup was also absent helpful error messages that identified SNAPPY as
ill-configured or subsequently, and the description on this issue, why regions
were being closed right after open or why they were not being assigned.
> 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-beta-2
>
>
> [~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
(v6.4.14#64029)
