hbase-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jean-Daniel Cryans (JIRA)" <j...@apache.org>
Subject [jira] Updated: (HBASE-1344) WARN IllegalStateException: Cannot set a region as open if it has not been pending
Date Wed, 20 May 2009 17:31:45 GMT

     [ https://issues.apache.org/jira/browse/HBASE-1344?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Jean-Daniel Cryans updated HBASE-1344:
--------------------------------------

    Fix Version/s: 0.19.3

> 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, 0.19.3
>
>         Attachments: basescanner.patch, 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}
> [stack@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.


Mime
View raw message