WARN IllegalStateException: Cannot set a region as open if it has not been
pending
----------------------------------------------------------------------------------
Key: HBASE-1344
URL: https://issues.apache.org/jira/browse/HBASE-1344
Project: Hadoop HBase
Issue Type: Bug
Reporter: stack
Fix For: 0.20.0
{code}
2009-04-24 18:25:05,029 [regionserver/0:0:0:0:0:0:0:0:60021] WARN
org.apache.hadoop.hbase.regionserver.HRegionServer: Processing message (Retry:
0)
java.io.IOException: java.io.IOException: java.lang.IllegalStateException:
Cannot set a region as open if it has not been pending. State:
name=TestTable,1833989850,1240597495855, unassigned=true, pendingOpen=false,
open=false, closing=false, pendingClose=false,
closed=false, offlined=false
at
org.apache.hadoop.hbase.master.RegionManager$RegionState.setOpen(RegionManager.java:1236)
at org.apache.hadoop.hbase.master.RegionManager.setOpen(RegionManager.java:805)
at
org.apache.hadoop.hbase.master.ServerManager.processRegionOpen(ServerManager.java:524)
at
org.apache.hadoop.hbase.master.ServerManager.processMsgs(ServerManager.java:390)
at
org.apache.hadoop.hbase.master.ServerManager.processRegionServerAllsWell(ServerManager.java:361)
at
org.apache.hadoop.hbase.master.ServerManager.regionServerReport(ServerManager.java:269)
at org.apache.hadoop.hbase.master.HMaster.regionServerReport(HMaster.java:601)
at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:632)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:909)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at
org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteExceptionHandler.java:94)
at
org.apache.hadoop.hbase.RemoteExceptionHandler.checkThrowable(RemoteExceptionHandler.java:48)
at
org.apache.hadoop.hbase.RemoteExceptionHandler.checkIOException(RemoteExceptionHandler.java:66)
at
org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:491)
at java.lang.Thread.run(Thread.java:619)
{code}
Here is the regions' lifecycle:
{code}
[st...@aa0-000-13 trunk]$ grep -e 'TestTable,1833989850,1240597495855'
logs/hbase-stack-regionserver-aa0-000-13.u.powerset.com.log
2009-04-24 18:24:59,640 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Opening region
TestTable,1833989850,1240597495855/1257748575
2009-04-24 18:24:59,666 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Next sequence id for region
TestTable,1833989850,1240597495855 is 183696121
2009-04-24 18:24:59,666 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
TestTable,1833989850,1240597495855/1257748575 available
2009-04-24 18:24:59,666 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Closing
TestTable,1833989850,1240597495855: compactions & flushes disabled
2009-04-24 18:24:59,666 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Updates disabled for region, no
outstanding scanners on TestTable,1833989850,1240597495855
2009-04-24 18:24:59,667 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: No more row locks outstanding on
region TestTable,1833989850,1240597495855
2009-04-24 18:24:59,667 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: Closed
TestTable,1833989850,1240597495855
2009-04-24 18:24:59,672 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.CompactSplitThread: region split, META
updated, and report to master all successful. Old region=REGION => {NAME =>
'TestTable,1832962724,124059744833
1', STARTKEY => '1832962724', ENDKEY => '', ENCODED => 1889052331, OFFLINE =>
true, SPLIT => true, TABLE => {{NAME => 'TestTable', IS_ROOT => 'false',
IS_META => 'false', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false',
COMPRESSION => 'NONE', VERSIONS => '3
', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY =>
'false', BLOCKCACHE => 'false'}], INDEXES => []}}, new regions:
TestTable,1832962724,1240597495855, TestTable,1833989850,1240597495855. Split
took 3sec
2009-04-24 18:25:02,011 [regionserver/0:0:0:0:0:0:0:0:60021] INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
TestTable,1833989850,1240597495855
2009-04-24 18:25:02,011 [regionserver/0:0:0:0:0:0:0:0:60021.worker] INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: MSG_REGION_OPEN:
TestTable,1833989850,1240597495855
2009-04-24 18:25:02,013 [regionserver/0:0:0:0:0:0:0:0:60021.worker] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Opening region
TestTable,1833989850,1240597495855/1257748575
2009-04-24 18:25:02,037 [regionserver/0:0:0:0:0:0:0:0:60021.worker] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Next sequence id for region
TestTable,1833989850,1240597495855 is 183696121
2009-04-24 18:25:02,037 [regionserver/0:0:0:0:0:0:0:0:60021.worker] INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
TestTable,1833989850,1240597495855/1257748575 available
2009-04-24 18:25:02,037 [regionserver/0:0:0:0:0:0:0:0:60021.worker] DEBUG
org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction requested
for region TestTable,1833989850,1240597495855/1257748575 because: Region open
check
2009-04-24 18:25:02,038 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on region
TestTable,1833989850,1240597495855
java.io.IOException: java.io.IOException: java.lang.IllegalStateException:
Cannot set a region as open if it has not been pending. State:
name=TestTable,1833989850,1240597495855, unassigned=true, pendingOpen=false,
open=false, closing=false, pendingClose=false,
closed=false, offlined=false
2009-04-24 18:25:05,042 [regionserver/0:0:0:0:0:0:0:0:60021] INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
TestTable,1833989850,1240597495855
2009-04-24 18:25:05,043 [regionserver/0:0:0:0:0:0:0:0:60021.worker] INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Worker: MSG_REGION_OPEN:
TestTable,1833989850,1240597495855
2009-04-24 18:25:07,628 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on region
TestTable,1833989850,1240597495855 in 5sec
2009-04-24 18:25:18,196 [IPC Server handler 1 on 60021] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Flush requested on
TestTable,1833989850,1240597495855
2009-04-24 18:25:18,196 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region
TestTable,1833989850,1240597495855. Current region memcache size 64.0m
2009-04-24 18:25:24,320 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] DEBUG
org.apache.hadoop.hbase.regionserver.Store: Added
hdfs://aa0-000-12.u.powerset.com:9000/hbasetrunk2/TestTable/1257748575/info/669389692274037086,
entries=58120, sequenceid=183754265,
memsize=64.0m, filesize=57.6m to TestTable,1833989850,1240597495855
2009-04-24 18:25:24,727 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush of ~64.0m
for region TestTable,1833989850,1240597495855 in 6531ms, sequence id=183754265,
compaction requested=f
alse
2009-04-24 18:25:27,299 [IPC Server handler 0 on 60021] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Flush requested on
TestTable,1833989850,1240597495855
2009-04-24 18:25:27,299 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region
TestTable,1833989850,1240597495855. Current region memcache size 64.0m
2009-04-24 18:25:32,722 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] DEBUG
org.apache.hadoop.hbase.regionserver.Store: Added
hdfs://aa0-000-12.u.powerset.com:9000/hbasetrunk2/TestTable/1257748575/info/4755763594728033629,
entries=58111, sequenceid=183812377
, memsize=64.0m, filesize=57.6m to TestTable,1833989850,1240597495855
2009-04-24 18:25:32,729 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush of ~64.0m
for region TestTable,1833989850,1240597495855 in 5430ms, sequence id=183812377,
compaction requested=t
rue
2009-04-24 18:25:32,729 [regionserver/0:0:0:0:0:0:0:0:60021.cacheFlusher] DEBUG
org.apache.hadoop.hbase.regionserver.CompactSplitThread: Compaction requested
for region TestTable,1833989850,1240597495855/1257748575 because:
regionserver/0:0:0:0:0:0:0:0:60021.cac
heFlusher
2009-04-24 18:25:32,730 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on region
TestTable,1833989850,1240597495855
2009-04-24 18:25:42,843 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on region
TestTable,1833989850,1240597495855 in 10sec
2009-04-24 18:25:42,846 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: Starting split of region
TestTable,1833989850,1240597495855
2009-04-24 18:25:42,849 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Closing
TestTable,1833989850,1240597495855: compactions & flushes disabled
2009-04-24 18:25:42,874 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Updates disabled for region, no
outstanding scanners on TestTable,1833989850,1240597495855
2009-04-24 18:25:42,874 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: No more row locks outstanding on
region TestTable,1833989850,1240597495855
2009-04-24 18:25:42,874 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Started memcache flush for region
TestTable,1833989850,1240597495855. Current region memcache size 58.8m
2009-04-24 18:25:45,045 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.Store: Added
hdfs://aa0-000-12.u.powerset.com:9000/hbasetrunk2/TestTable/1257748575/info/3148860415324952525,
entries=53415, sequenceid=183865794, m
emsize=58.8m, filesize=52.9m to TestTable,1833989850,1240597495855
2009-04-24 18:25:45,046 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] DEBUG
org.apache.hadoop.hbase.regionserver.HRegion: Finished memcache flush of ~58.8m
for region TestTable,1833989850,1240597495855 in 2172ms, sequence id=183865794,
compaction requested=true
2009-04-24 18:25:45,046 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.HRegion: Closed
TestTable,1833989850,1240597495855
2009-04-24 18:25:45,369 [regionserver/0:0:0:0:0:0:0:0:60021.compactor] INFO
org.apache.hadoop.hbase.regionserver.CompactSplitThread: region split, META
updated, and report to master all successful. Old region=REGION => {NAME =>
'TestTable,1833989850,124059749585
5', STARTKEY => '1833989850', ENDKEY => '', ENCODED => 1257748575, OFFLINE =>
true, SPLIT => true, TABLE => {{NAME => 'TestTable', IS_ROOT => 'false',
IS_META => 'false', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'false',
COMPRESSION => 'NONE', VERSIONS => '3
', LENGTH => '2147483647', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY =>
'false', BLOCKCACHE => 'false'}], INDEXES => []}}, new regions:
TestTable,1833989850,1240597542848, TestTable,1835061689,1240597542848. Split
took 2sec
{code}
Odd, is that it seems to go on in spite of ISE... so just a warning? Why an
open w/o first being pending?
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
