[
https://issues.apache.org/jira/browse/HBASE-1344?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-1344:
-------------------------
Attachment: rm3.patch
This one seems to fix things. Its been running all day and no warnings.
Cleaned up the toString on table descriptor and column descriptor to not emit
read-only values and to not emit bloomfilter state.
> 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
> Assignee: stack
> Fix For: 0.20.0
>
> Attachments: rm.patch, rm3.patch
>
>
> {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.
