You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by Sebastian Bauer <ad...@ugame.net.pl> on 2010/10/23 20:21:51 UTC

NPE after restarting

Today i found this problem after restarting hbase:


2010-10-23 20:16:17,882 DEBUG
org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
Lookedup root region location,
connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionIm
2010-10-23 20:16:17,890 DEBUG
org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
Cached location for .META.,,1.1028785192 is
db2a.goldenline.pl:60020                                    
2010-10-23 20:16:18,432 FATAL org.apache.hadoop.hbase.master.HMaster:
Unhandled exception. Starting
shutdown.                                                                                                      

java.lang.NullPointerException                                                                                                                                                                                     

        at
org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)                                                                                                                                   

        at
org.apache.hadoop.hbase.util.Writables.getHRegionInfo(Writables.java:119)                                                                                                                               

        at
org.apache.hadoop.hbase.client.MetaScanner$1.processRow(MetaScanner.java:188)                                                                                                                           

        at
org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:157)                                                                                                                               

        at
org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:69)                                                                                                                                

        at
org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:54)                                                                                                                                

        at
org.apache.hadoop.hbase.client.MetaScanner.listAllRegions(MetaScanner.java:195)                                                                                                                         

        at
org.apache.hadoop.hbase.master.AssignmentManager.assignAllUserRegions(AssignmentManager.java:1048)                                                                                                      

        at
org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:379)                                                                                                                           

        at
org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:265)                                                                                                                                            

2010-10-23 20:16:18,433 INFO org.apache.hadoop.hbase.master.HMaster:
Aborting                                                                                                                                      

2010-10-23 20:16:18,433 DEBUG org.apache.hadoop.hbase.master.HMaster:
Stopping service threads                    

Re: NPE after restarting

Posted by Sebastian Bauer <ad...@ugame.net.pl>.
../hadoop/bin/hadoop fs -cat /hbase/hbase.version
7

hbase revision:
1026606

W dniu 23.10.2010 23:12, Sebastian Bauer pisze:
> This happen again, i cannot start hbase so any log data need to be get
> from hadoop
>
> W dniu 23.10.2010 22:17, Stack pisze:
>> If you restart master again, still NPE?  What version of hbase?  So,
>> your meta has an empty info:regioninfo cell.  When you do ./bin/hbase,
>> is there an hbck to run?  If so, run it and what does it report?
>> StAck
>>
>> On Sat, Oct 23, 2010 at 11:21 AM, Sebastian Bauer <ad...@ugame.net.pl> wrote:
>>> Today i found this problem after restarting hbase:
>>>
>>>
>>> 2010-10-23 20:16:17,882 DEBUG
>>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>>> Lookedup root region location,
>>> connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionIm
>>> 2010-10-23 20:16:17,890 DEBUG
>>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>>> Cached location for .META.,,1.1028785192 is
>>> db2a.goldenline.pl:60020
>>> 2010-10-23 20:16:18,432 FATAL org.apache.hadoop.hbase.master.HMaster:
>>> Unhandled exception. Starting
>>> shutdown.
>>>
>>> java.lang.NullPointerException
>>>
>>>        at
>>> org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
>>>
>>>        at
>>> org.apache.hadoop.hbase.util.Writables.getHRegionInfo(Writables.java:119)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner$1.processRow(MetaScanner.java:188)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:157)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:69)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:54)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.listAllRegions(MetaScanner.java:195)
>>>
>>>        at
>>> org.apache.hadoop.hbase.master.AssignmentManager.assignAllUserRegions(AssignmentManager.java:1048)
>>>
>>>        at
>>> org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:379)
>>>
>>>        at
>>> org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:265)
>>>
>>> 2010-10-23 20:16:18,433 INFO org.apache.hadoop.hbase.master.HMaster:
>>> Aborting
>>>
>>> 2010-10-23 20:16:18,433 DEBUG org.apache.hadoop.hbase.master.HMaster:
>>> Stopping service threads
>>>
>


-- 

Pozdrawiam
Sebastian Bauer
-----------------------------------------------------
http://tikecik.pl


Re: NPE after restarting

Posted by Sebastian Bauer <ad...@ugame.net.pl>.
This happen again, i cannot start hbase so any log data need to be get
from hadoop

W dniu 23.10.2010 22:17, Stack pisze:
> If you restart master again, still NPE?  What version of hbase?  So,
> your meta has an empty info:regioninfo cell.  When you do ./bin/hbase,
> is there an hbck to run?  If so, run it and what does it report?
> StAck
>
> On Sat, Oct 23, 2010 at 11:21 AM, Sebastian Bauer <ad...@ugame.net.pl> wrote:
>> Today i found this problem after restarting hbase:
>>
>>
>> 2010-10-23 20:16:17,882 DEBUG
>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>> Lookedup root region location,
>> connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionIm
>> 2010-10-23 20:16:17,890 DEBUG
>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>> Cached location for .META.,,1.1028785192 is
>> db2a.goldenline.pl:60020
>> 2010-10-23 20:16:18,432 FATAL org.apache.hadoop.hbase.master.HMaster:
>> Unhandled exception. Starting
>> shutdown.
>>
>> java.lang.NullPointerException
>>
>>        at
>> org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
>>
>>        at
>> org.apache.hadoop.hbase.util.Writables.getHRegionInfo(Writables.java:119)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner$1.processRow(MetaScanner.java:188)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:157)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:69)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:54)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.listAllRegions(MetaScanner.java:195)
>>
>>        at
>> org.apache.hadoop.hbase.master.AssignmentManager.assignAllUserRegions(AssignmentManager.java:1048)
>>
>>        at
>> org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:379)
>>
>>        at
>> org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:265)
>>
>> 2010-10-23 20:16:18,433 INFO org.apache.hadoop.hbase.master.HMaster:
>> Aborting
>>
>> 2010-10-23 20:16:18,433 DEBUG org.apache.hadoop.hbase.master.HMaster:
>> Stopping service threads
>>


-- 

Pozdrawiam
Sebastian Bauer
-----------------------------------------------------
http://tikecik.pl


NPE caught in CatalogJanitor

Posted by Sebastian Bauer <ad...@ugame.net.pl>.
Hi, do you have any ideas what can cause this error:


2010-10-25 08:13:00,933 DEBUG
org.apache.hadoop.hbase.master.LoadBalancer: Skipping load balancing.
servers=2 regions=5073 average=2536.5 mostloaded=2537 leastloaded=2537
2010-10-25 08:13:01,690 WARN
org.apache.hadoop.hbase.master.CatalogJanitor: REGIONINFO_QUALIFIER is
empty in
keyvalues={ZNANYLEKARZ_CTU,67-w_2010_36_6C8010B775B90B091CA2B04D2CA7CD49,1287059084055.83fda231f456837b4c9316d433bb89bc./info:server/1287909181224/Put/vlen=24,
ZNANY
LEKARZ_CTU,67-w_2010_36_6C8010B775B90B091CA2B04D2CA7CD49,1287059084055.83fda231f456837b4c9316d433bb89bc./info:serverstartcode/1287909181224/Put/vlen=8}

2010-10-25 08:13:01,690 ERROR
org.apache.hadoop.hbase.master.CatalogJanitor: Caught exception
java.lang.NullPointerException
2010-10-25 08:13:24,385 INFO
org.apache.hadoop.hbase.master.ServerManager: regionservers=2,
averageload=2538


I see a lot of this in logs and its happens after load balancing.

hadoop direcotory listing:

hbase@db2a:hbase$ ./hadoop/bin/hadoop fs -ls
/hbase/ZNANYLEKARZ_CTU/83fda231f456837b4c9316d433bb89bc
Found 2 items
-rw-r--r-- 2 hbase supergroup 1008 2010-10-24 10:33
/hbase/ZNANYLEKARZ_CTU/83fda231f456837b4c9316d433bb89bc/.regioninfo
drwxr-xr-x - hbase supergroup 0 2010-10-24 10:33
/hbase/ZNANYLEKARZ_CTU/83fda231f456837b4c9316d433bb89bc/c
hbase@db2a:hbase$ ./hadoop/bin/hadoop fs -ls
/hbase/ZNANYLEKARZ_CTU/83fda231f456837b4c9316d433bb89bc/c
hbase@db2a:hbase$

hbase@db2a:hbase$ ./hadoop/bin/hadoop fs -cat
/hbase/ZNANYLEKARZ_CTU/83fda231f456837b4c9316d433bb89bc/.regioninfo
%73-g_20A8406500E1593C617327A77113AFB9+��mZNANYLEKARZ_CTU,67-w_2010_36_6C8010B775B90B091CA2B04D2CA7CD49,1287059084055.83fda231f456837b4c9316d433bb89bc.-67-w_2010_36_6C8010B775B90B091CA2B04D2CA7CD49ZNANYLEKARZ_CTUIS_ROOTfalseIS_METAfalsBLOOMFILTERROWREPLICATION_SCOPEVERSIONS1COMPRESSIONLZOTTL-1
BLOCKSIZE65536 IN_MEMORYfalse
BLOCKCACHEtrue�3��

REGION => {NAME =>
'ZNANYLEKARZ_CTU,67-w_2010_36_6C8010B775B90B091CA2B04D2CA7CD49,1287059084055.83fda231f456837b4c9316d433bb89bc.',
STARTKEY => '67-w_2010_36_6C8010B775B90B091CA2B04D2CA7CD49', ENDKEY =>
'73-g_20A8406500E1593C617327A77113AFB9', ENCODED =>
83fda231f456837b4c9316d433bb89bc, OFFLINE => true, SPLIT => true, TABLE
=> {{NAME => 'ZNANYLEKARZ_CTU', FAMILIES => [{NAME => 'c', BLOOMFILTER
=> 'ROW', REPLICATION_SCOPE => '0', VERSIONS => '1', COMPRESSION =>
'LZO', TTL => '-1', BLOCKSIZE => '65536', IN_MEMORY => 'false',
BLOCKCACHE => 'true'}]}}hbase@db2a:hbase$




Re: NPE after restarting

Posted by Stack <st...@duboce.net>.
Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d. is the
region missing a regioninfo.  You could try deleting this row from
.META.   See hbase will start then.  But then you'll have a hole in
your table.  Is there a directory in hdfs named under your
hbase.rootdir named Golden_SUN_new/e3d331be0a8b19acd6e9e40e858cf59d ?
If so, is there a .regioninfo in there?  If so, this has the info
you'd need to reinsert an entry into .META.  It actually has the
.regioninfo too.  If you were any good w/ ruby you could read in this
file and insert its content into .META.  See bin/loadtable.rb for
example.  Or, just reload whole table with bin/loadtable.rb?

St.Ack

On Sat, Oct 23, 2010 at 1:49 PM, Sebastian Bauer <ad...@ugame.net.pl> wrote:
> 2010-10-23 21:26:24,527 DEBUG
> org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:60000-0x12bda8e37060000 Async create of unassigned node for
> e3d331be0a8b19acd6e9e40e858cf59d with OFFLINE state
> 2010-10-23 21:26:24,823 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager$CreateUnassignedAsyncCallback:
> rs=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
> state=OFFLINE, ts=1287861984527, se
> rver=db2b.goldenline.pl,60020,1287861976536
> 2010-10-23 21:26:24,951 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager$ExistsUnassignedAsyncCallback:
> rs=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
> state=OFFLINE, ts=1287861984527
> 2010-10-23 21:26:46,146 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=db2b.goldenline.pl,60020,1287861976536,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:26:46,238 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENED,
> server=db2b.goldenline.pl,60020,1287861976536,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:26:46,238 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling
> OPENED event for e3d331be0a8b19acd6e9e40e858cf59d; deleting unassigned node
> 2010-10-23 21:26:46,238 DEBUG
> org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:60000-0x12bda8e37060000 Deleting existing unassigned node for
> e3d331be0a8b19acd6e9e40e858cf59d that is in expected state
> RS_ZK_REGION_OPENED
> 2010-10-23 21:26:46,288 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened
> region Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
> 2010-10-23 21:32:37,943 INFO org.apache.hadoop.hbase.master.HMaster:
> balance
> hri=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.,
> src=db2b.goldenline.pl,60020,1287861976536,
> dest=db2a.goldenline.pl,60020,1287861976949
> 2010-10-23 21:32:37,943 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment
> of region
> Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d. (offlining)
> 2010-10-23 21:32:37,955 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling new
> unassigned node: /hbase/unassigned/e3d331be0a8b19acd6e9e40e858cf59d
> (region=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.,
> server=db2b.goldenline.pl,60020,1287861976536, state=RS_ZK_REGION_CLOSING)
> 2010-10-23 21:32:37,955 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_CLOSING,
> server=db2b.goldenline.pl,60020,1287861976536,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:32:37,956 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_CLOSED,
> server=db2b.goldenline.pl,60020,1287861976536,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:32:37,956 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE;
> was=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
> state=CLOSED, ts=1287862357885
> 2010-10-23 21:32:37,956 DEBUG
> org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:60000-0x12bda8e37060000 Creating (or updating) unassigned node
> for e3d331be0a8b19acd6e9e40e858cf59d with OFFLINE state
> 2010-10-23 21:32:37,968 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Using preexisting
> plan=hri=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d., src=db2b.goldenline.pl,60020,1287861976536,
> dest=db2a.goldenline.pl,60020,1287861976949
> 2010-10-23 21:32:37,968 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
> Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d. to
> db2a.goldenline.pl,60020,1287861976949
> 2010-10-23 21:32:37,971 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=M_ZK_REGION_OFFLINE, server=db2a.goldenline.pl:60000,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:32:37,977 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=db2a.goldenline.pl,60020,1287861976949,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:32:38,025 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=db2a.goldenline.pl,60020,1287861976949,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:32:38,053 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENED,
> server=db2a.goldenline.pl,60020,1287861976949,
> region=e3d331be0a8b19acd6e9e40e858cf59d
> 2010-10-23 21:32:38,053 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling
> OPENED event for e3d331be0a8b19acd6e9e40e858cf59d; deleting unassigned node
> 2010-10-23 21:32:38,053 DEBUG
> org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:60000-0x12bda8e37060000 Deleting existing unassigned node for
> e3d331be0a8b19acd6e9e40e858cf59d that is in expected state
> RS_ZK_REGION_OPENED
> 2010-10-23 21:32:38,054 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened
> region Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
> 2010-10-23 21:37:37,943 WARN
> org.apache.hadoop.hbase.master.CatalogJanitor: REGIONINFO_QUALIFIER is
> empty in
> keyvalues={Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:server/1287862357956/Put/vlen=24,
> Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:serverstartcode/1287862357956/Put/vlen=8}
> 2010-10-23 21:42:37,954 WARN
> org.apache.hadoop.hbase.master.CatalogJanitor: REGIONINFO_QUALIFIER is
> empty in
> keyvalues={Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:server/1287862357956/Put/vlen=24,
> Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:serverstartcode/1287862357956/Put/vlen=8}
>
>
> W dniu 23.10.2010 22:47, Stack pisze:
>> grep 'e3d331be0a8b19acd6e9e40e858cf59d' logs/hbase-master.log
>
>
> --
>
> Pozdrawiam
> Sebastian Bauer
> -----------------------------------------------------
> http://tikecik.pl
>
>

Re: NPE after restarting

Posted by Sebastian Bauer <ad...@ugame.net.pl>.
2010-10-23 21:26:24,527 DEBUG
org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:60000-0x12bda8e37060000 Async create of unassigned node for
e3d331be0a8b19acd6e9e40e858cf59d with OFFLINE state
2010-10-23 21:26:24,823 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager$CreateUnassignedAsyncCallback:
rs=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
state=OFFLINE, ts=1287861984527, se
rver=db2b.goldenline.pl,60020,1287861976536
2010-10-23 21:26:24,951 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager$ExistsUnassignedAsyncCallback:
rs=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
state=OFFLINE, ts=1287861984527
2010-10-23 21:26:46,146 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENING,
server=db2b.goldenline.pl,60020,1287861976536,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:26:46,238 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENED,
server=db2b.goldenline.pl,60020,1287861976536,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:26:46,238 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling
OPENED event for e3d331be0a8b19acd6e9e40e858cf59d; deleting unassigned node
2010-10-23 21:26:46,238 DEBUG
org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:60000-0x12bda8e37060000 Deleting existing unassigned node for
e3d331be0a8b19acd6e9e40e858cf59d that is in expected state
RS_ZK_REGION_OPENED
2010-10-23 21:26:46,288 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened
region Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
2010-10-23 21:32:37,943 INFO org.apache.hadoop.hbase.master.HMaster:
balance
hri=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.,
src=db2b.goldenline.pl,60020,1287861976536,
dest=db2a.goldenline.pl,60020,1287861976949
2010-10-23 21:32:37,943 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment
of region
Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d. (offlining)
2010-10-23 21:32:37,955 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling new
unassigned node: /hbase/unassigned/e3d331be0a8b19acd6e9e40e858cf59d
(region=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.,
server=db2b.goldenline.pl,60020,1287861976536, state=RS_ZK_REGION_CLOSING)
2010-10-23 21:32:37,955 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_CLOSING,
server=db2b.goldenline.pl,60020,1287861976536,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:32:37,956 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_CLOSED,
server=db2b.goldenline.pl,60020,1287861976536,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:32:37,956 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE;
was=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
state=CLOSED, ts=1287862357885
2010-10-23 21:32:37,956 DEBUG
org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:60000-0x12bda8e37060000 Creating (or updating) unassigned node
for e3d331be0a8b19acd6e9e40e858cf59d with OFFLINE state
2010-10-23 21:32:37,968 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Using preexisting
plan=hri=Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d., src=db2b.goldenline.pl,60020,1287861976536,
dest=db2a.goldenline.pl,60020,1287861976949
2010-10-23 21:32:37,968 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d. to
db2a.goldenline.pl,60020,1287861976949
2010-10-23 21:32:37,971 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=M_ZK_REGION_OFFLINE, server=db2a.goldenline.pl:60000,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:32:37,977 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENING,
server=db2a.goldenline.pl,60020,1287861976949,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:32:38,025 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENING,
server=db2a.goldenline.pl,60020,1287861976949,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:32:38,053 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENED,
server=db2a.goldenline.pl,60020,1287861976949,
region=e3d331be0a8b19acd6e9e40e858cf59d
2010-10-23 21:32:38,053 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling
OPENED event for e3d331be0a8b19acd6e9e40e858cf59d; deleting unassigned node
2010-10-23 21:32:38,053 DEBUG
org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:60000-0x12bda8e37060000 Deleting existing unassigned node for
e3d331be0a8b19acd6e9e40e858cf59d that is in expected state
RS_ZK_REGION_OPENED
2010-10-23 21:32:38,054 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened
region Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d.
2010-10-23 21:37:37,943 WARN
org.apache.hadoop.hbase.master.CatalogJanitor: REGIONINFO_QUALIFIER is
empty in
keyvalues={Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:server/1287862357956/Put/vlen=24,
Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:serverstartcode/1287862357956/Put/vlen=8}
2010-10-23 21:42:37,954 WARN
org.apache.hadoop.hbase.master.CatalogJanitor: REGIONINFO_QUALIFIER is
empty in
keyvalues={Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:server/1287862357956/Put/vlen=24,
Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./info:serverstartcode/1287862357956/Put/vlen=8}


W dniu 23.10.2010 22:47, Stack pisze:
> grep 'e3d331be0a8b19acd6e9e40e858cf59d' logs/hbase-master.log


-- 

Pozdrawiam
Sebastian Bauer
-----------------------------------------------------
http://tikecik.pl


Re: NPE after restarting

Posted by Stack <st...@duboce.net>.
ok...

Grep the meta row key in master log and see if you can tell a story
about what happened to that region....

grep 'e3d331be0a8b19acd6e9e40e858cf59d' logs/hbase-master.log


St.Ack

On Sat, Oct 23, 2010 at 1:38 PM, Sebastian Bauer <ad...@ugame.net.pl> wrote:
> this was on production so i created full backup of /hbase dir and
> deleted .META. from hadoop, in monday i will have access to test servers
> so i will give you more logs.
> but before restart i saw many of this:
>
> 2010-10-23 22:32:37,942 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment
> of region
> Golden_UTA,0C4780DF3A4817A55C54824B53D45F91-7519_d_2010_9_10,1287069029997.
> 2010-10-23 22:32:37,945 WARN
> org.apache.hadoop.hbase.master.CatalogJanitor: REGIONINFO_QUALIFIER is
> empty in
> keyvalues={Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./inf
> 2010-10-23 22:32:37,945 ERROR
> org.apache.hadoop.hbase.master.CatalogJanitor: Caught
> exception
>
> java.lang.NullPointerException
>
>        at
> org.apache.hadoop.hbase.master.CatalogJanitor$1.visit(CatalogJanitor.java:101)
>
>        at
> org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:197)
>
>        at
> org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:107)
>
>        at
> org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:77)
>
>        at
> org.apache.hadoop.hbase.Chore.run(Chore.java:66)
>
>
> W dniu 23.10.2010 22:17, Stack pisze:
>> If you restart master again, still NPE?  What version of hbase?  So,
>> your meta has an empty info:regioninfo cell.  When you do ./bin/hbase,
>> is there an hbck to run?  If so, run it and what does it report?
>> StAck
>>
>> On Sat, Oct 23, 2010 at 11:21 AM, Sebastian Bauer <ad...@ugame.net.pl> wrote:
>>> Today i found this problem after restarting hbase:
>>>
>>>
>>> 2010-10-23 20:16:17,882 DEBUG
>>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>>> Lookedup root region location,
>>> connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionIm
>>> 2010-10-23 20:16:17,890 DEBUG
>>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>>> Cached location for .META.,,1.1028785192 is
>>> db2a.goldenline.pl:60020
>>> 2010-10-23 20:16:18,432 FATAL org.apache.hadoop.hbase.master.HMaster:
>>> Unhandled exception. Starting
>>> shutdown.
>>>
>>> java.lang.NullPointerException
>>>
>>>        at
>>> org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
>>>
>>>        at
>>> org.apache.hadoop.hbase.util.Writables.getHRegionInfo(Writables.java:119)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner$1.processRow(MetaScanner.java:188)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:157)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:69)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:54)
>>>
>>>        at
>>> org.apache.hadoop.hbase.client.MetaScanner.listAllRegions(MetaScanner.java:195)
>>>
>>>        at
>>> org.apache.hadoop.hbase.master.AssignmentManager.assignAllUserRegions(AssignmentManager.java:1048)
>>>
>>>        at
>>> org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:379)
>>>
>>>        at
>>> org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:265)
>>>
>>> 2010-10-23 20:16:18,433 INFO org.apache.hadoop.hbase.master.HMaster:
>>> Aborting
>>>
>>> 2010-10-23 20:16:18,433 DEBUG org.apache.hadoop.hbase.master.HMaster:
>>> Stopping service threads
>>>
>
>
> --
>
> Pozdrawiam
> Sebastian Bauer
> -----------------------------------------------------
> http://tikecik.pl
>
>

Re: NPE after restarting

Posted by Sebastian Bauer <ad...@ugame.net.pl>.
this was on production so i created full backup of /hbase dir and
deleted .META. from hadoop, in monday i will have access to test servers
so i will give you more logs.
but before restart i saw many of this:

2010-10-23 22:32:37,942 DEBUG
org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment
of region
Golden_UTA,0C4780DF3A4817A55C54824B53D45F91-7519_d_2010_9_10,1287069029997.
2010-10-23 22:32:37,945 WARN
org.apache.hadoop.hbase.master.CatalogJanitor: REGIONINFO_QUALIFIER is
empty in
keyvalues={Golden_SUN_new,,1286037947793.e3d331be0a8b19acd6e9e40e858cf59d./inf
2010-10-23 22:32:37,945 ERROR
org.apache.hadoop.hbase.master.CatalogJanitor: Caught
exception                                                                                             

java.lang.NullPointerException                                                                                                                                                            

        at
org.apache.hadoop.hbase.master.CatalogJanitor$1.visit(CatalogJanitor.java:101)                                                                                                 

        at
org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:197)                                                                                                       

        at
org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:107)                                                                                                    

        at
org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:77)                                                                                                    

        at
org.apache.hadoop.hbase.Chore.run(Chore.java:66)                        


W dniu 23.10.2010 22:17, Stack pisze:
> If you restart master again, still NPE?  What version of hbase?  So,
> your meta has an empty info:regioninfo cell.  When you do ./bin/hbase,
> is there an hbck to run?  If so, run it and what does it report?
> StAck
>
> On Sat, Oct 23, 2010 at 11:21 AM, Sebastian Bauer <ad...@ugame.net.pl> wrote:
>> Today i found this problem after restarting hbase:
>>
>>
>> 2010-10-23 20:16:17,882 DEBUG
>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>> Lookedup root region location,
>> connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionIm
>> 2010-10-23 20:16:17,890 DEBUG
>> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
>> Cached location for .META.,,1.1028785192 is
>> db2a.goldenline.pl:60020
>> 2010-10-23 20:16:18,432 FATAL org.apache.hadoop.hbase.master.HMaster:
>> Unhandled exception. Starting
>> shutdown.
>>
>> java.lang.NullPointerException
>>
>>        at
>> org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
>>
>>        at
>> org.apache.hadoop.hbase.util.Writables.getHRegionInfo(Writables.java:119)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner$1.processRow(MetaScanner.java:188)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:157)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:69)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:54)
>>
>>        at
>> org.apache.hadoop.hbase.client.MetaScanner.listAllRegions(MetaScanner.java:195)
>>
>>        at
>> org.apache.hadoop.hbase.master.AssignmentManager.assignAllUserRegions(AssignmentManager.java:1048)
>>
>>        at
>> org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:379)
>>
>>        at
>> org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:265)
>>
>> 2010-10-23 20:16:18,433 INFO org.apache.hadoop.hbase.master.HMaster:
>> Aborting
>>
>> 2010-10-23 20:16:18,433 DEBUG org.apache.hadoop.hbase.master.HMaster:
>> Stopping service threads
>>


-- 

Pozdrawiam
Sebastian Bauer
-----------------------------------------------------
http://tikecik.pl


Re: NPE after restarting

Posted by Stack <st...@duboce.net>.
If you restart master again, still NPE?  What version of hbase?  So,
your meta has an empty info:regioninfo cell.  When you do ./bin/hbase,
is there an hbck to run?  If so, run it and what does it report?
StAck

On Sat, Oct 23, 2010 at 11:21 AM, Sebastian Bauer <ad...@ugame.net.pl> wrote:
> Today i found this problem after restarting hbase:
>
>
> 2010-10-23 20:16:17,882 DEBUG
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Lookedup root region location,
> connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionIm
> 2010-10-23 20:16:17,890 DEBUG
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Cached location for .META.,,1.1028785192 is
> db2a.goldenline.pl:60020
> 2010-10-23 20:16:18,432 FATAL org.apache.hadoop.hbase.master.HMaster:
> Unhandled exception. Starting
> shutdown.
>
> java.lang.NullPointerException
>
>        at
> org.apache.hadoop.hbase.util.Writables.getWritable(Writables.java:75)
>
>        at
> org.apache.hadoop.hbase.util.Writables.getHRegionInfo(Writables.java:119)
>
>        at
> org.apache.hadoop.hbase.client.MetaScanner$1.processRow(MetaScanner.java:188)
>
>        at
> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:157)
>
>        at
> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:69)
>
>        at
> org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:54)
>
>        at
> org.apache.hadoop.hbase.client.MetaScanner.listAllRegions(MetaScanner.java:195)
>
>        at
> org.apache.hadoop.hbase.master.AssignmentManager.assignAllUserRegions(AssignmentManager.java:1048)
>
>        at
> org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:379)
>
>        at
> org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:265)
>
> 2010-10-23 20:16:18,433 INFO org.apache.hadoop.hbase.master.HMaster:
> Aborting
>
> 2010-10-23 20:16:18,433 DEBUG org.apache.hadoop.hbase.master.HMaster:
> Stopping service threads
>