It is my understanding that the log splitting going on is a process of taking
recent updates and applying those changes to the appropriate regions. Is there
a way I can remove those "logs" or recent edits safely, so that the master
doesn't have to do any log splitting on start up?
I am willing to lose a small amount of data just to be able to get back up and
running. What kind of surgery would I need to do on the file system?
-Matthew
On Oct 3, 2010, at 12:55 PM, Matthew LeMieux wrote:
> I probably wasn't clear on this in the previous message. There are NO
> exceptions reported in the log file. It appears as though the master is
> attempting to do the log splits (see below 21 of 36 at 2010-10-03
> 18:13:28,187), and then immediately transitions into the "Closed" messages,
> again with NO exceptions being reported - it just stops doing the log
> splitting. After the "Closed" messages start there are no further log
> splitting messages in the log file. It just does a series of those, and then
> moves on to reporting 0 region servers again. Again, NO other messages are
> being sent to the log file.
>
> -Matthew
>
>
>
> On Oct 3, 2010, at 12:33 PM, Matthew LeMieux wrote:
>
>> It think it is a bit more serious than that. Waiting doesn't appear to do
>> much.
>>
>> After a series of log messages that appear to be doing the splitting, the
>> "Closed", messages appear:
>>
>> 2010-10-03 18:13:26,664 INFO org.apache.hadoop.hbase.util.FSUtils:
>> Recovering
>> filehdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.1284820404595
>> 2010-10-03 18:13:26,701 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 18:13:26,872 INFO org.apache.hadoop.hbase.util.FSUtils: Finished
>> lease recover attempt for
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.128482040459
>> 5
>> 2010-10-03 18:13:27,500 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Pushed=5211 entries from
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.128482040459
>> 5
>> 2010-10-03 18:13:27,500 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Splitting hlog 20 of 36:
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.128482041398
>> 9, length=64550958
>> 2010-10-03 18:13:27,500 INFO org.apache.hadoop.hbase.util.FSUtils:
>> Recovering
>> filehdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.1284820413989
>> 2010-10-03 18:13:27,721 INFO org.apache.hadoop.hbase.util.FSUtils: Finished
>> lease recover attempt for
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.128482041398
>> 9
>> 2010-10-03 18:13:28,187 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Pushed=4555 entries from
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.128482041398
>> 9
>> 2010-10-03 18:13:28,187 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Splitting hlog 21 of 36:
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.1284820433464,
>> length=2373620705
>> 2010-10-03 18:13:28,187 INFO org.apache.hadoop.hbase.util.FSUtils:
>> Recovering
>> filehdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.1284820433464
>> 2010-10-03 18:13:28,391 INFO org.apache.hadoop.hbase.util.FSUtils: Finished
>> lease recover attempt for
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.1284820433464
>> 2010-10-03 18:13:42,141 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Pushed=65522 entries from
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/.logs/domU-12-31-39-18-12-05.compute-1.internal,60020,1284222361677/10.104.37.247%3A60020.1284820433464
>> 2010-10-03 18:13:42,533 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Closed
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/dirgraph/e2a8b3352d84523be7f43f966bde6ef1/recovered.edits/0000000000075378488
>> 2010-10-03 18:13:42,539 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Closed
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/dirgraph/e3a7a269aa9f1b32de6b3add53cc5a30/recovered.edits/0000000000075400136
>> 2010-10-03 18:13:42,546 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Closed
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/dirgraph/32d50d0d37a5ed3f89f17772678c4c20/recovered.edits/0000000000075400152
>> 2010-10-03 18:13:42,550 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Closed
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/dirgraph/182719f8ad5c2c7da56bdd3987a4559c/recovered.edits/0000000000075471128
>> 2010-10-03 18:13:42,555 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Closed
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/dirgraph/4148aa42cf9ac956c0e048b83ca6f186/recovered.edits/0000000000075463238
>> 2010-10-03 18:13:42,560 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog:
>> Closed
>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/dirgraph/9d4edffd841fb66c37ab5944f12ef911/recovered.edits/0000000000075393635
>> 2
>>
>> Then the ONLY messages that are appear in the master's log file are these:
>>
>> 2010-10-03 18:55:27,130 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 18:56:27,140 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 18:57:27,150 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 18:58:27,160 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 18:59:27,170 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:00:27,180 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:01:27,190 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:02:27,200 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:03:27,215 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:04:27,225 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:05:27,235 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:06:27,245 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:07:27,255 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:08:27,265 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:09:27,275 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:10:27,285 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:11:27,295 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:12:27,305 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:13:27,315 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:14:27,325 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:15:27,335 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:16:27,348 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:17:27,358 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:18:27,368 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:19:27,378 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:20:27,388 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:21:27,388 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:22:27,388 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:23:27,388 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:24:27,388 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:25:27,388 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>> 2010-10-03 19:26:27,388 INFO org.apache.hadoop.hbase.master.ServerManager: 0
>> region servers, 0 dead, average load NaN
>>
>> I'm not pulling any lines out, ALL regions servers are just waiting for the
>> master, with NO lines being written to the log file. I tried killing the
>> master, and restarting, clearly the region servers are aware of the master,
>> but the master persists in not recognizing them:
>>
>> 2010-10-03 18:11:35,888 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
>> state: SyncConnected, type: NodeDeleted, path: /hbase/master
>> 2010-10-03 18:11:35,891 DEBUG
>> org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper:
>> <10.249.70.255:/hbase,domU-12-31-39-18-1B-05.compute-1.internal,60020,1286127632413>Set
>> watcher on master address ZNode /hbase/master
>> 2010-10-03 18:12:26,697 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Got ZooKeeper event,
>> state: SyncConnected, type: NodeCreated, path: /hbase/master
>> 2010-10-03 18:12:26,698 DEBUG
>> org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper:
>> <10.249.70.255:/hbase,domU-12-31-39-18-1B-05.compute-1.internal,60020,1286127632413>Read
>> ZNode /hbase/master got 10.104.37.247:60000
>> 2010-10-03 18:12:26,698 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Telling master at
>> 10.104.37.247:60000 that we are up
>>
>> This is clearly a not a situation of just waiting it out. A region server
>> killed itself, restarting the region server didn't get the cluster back up
>> and running. I restarted everything from scratch, and that brings us to the
>> current state. The machines are not doing anything, they have a load
>> average of 0.00 and cpu idle of more than 99%.
>>
>> What would cause the cluster to completely lock up and refuse to do anything?
>>
>> Thank you for your help,
>>
>> Matthew
>>
>> On Oct 3, 2010, at 12:02 PM, Jean-Daniel Cryans wrote:
>>
>>> From the brief looks of it, it seems that the master is splitting the
>>> log files from the dead region server. It will do that while the
>>> cluster is running and will keep answering the other region servers,
>>> but if you restart HBase then when the master starts it will split
>>> everything before starting to take region server checkins. Just let
>>> the master finish it's job. Look for this message that tells you which
>>> region server's hlogs are being split:
>>>
>>> LOG.info("Splitting " + logfiles.length + " hlog(s) in " +
>>> srcDir.toString());
>>>
>>> Then this message will show when it's done:
>>>
>>> LOG.info("hlog file splitting completed in " + (endMillis - millis) +
>>> " millis for " + srcDir.toString());
>>>
>>> J-D
>>>
>>> On Sun, Oct 3, 2010 at 10:56 AM, Matthew LeMieux <[email protected]>
>>> wrote:
>>>> I've recently had a region server suicide, and am not able to recover from
>>>> it. I've tried completely stopping the entire cluster and restarting it
>>>> (including dfs and zk), but the master refuses to recognize the
>>>> regionservers.
>>>>
>>>> The region servers appear to just be waiting for the master with this in
>>>> their log file:
>>>>
>>>> 2010-10-03 17:40:32,748 DEBUG
>>>> org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper:
>>>> <10.249.70.255:/hbase,domU-12-31-39-18-1B-05.compute-1.internal,60020,1286127632413>Read
>>>> ZNode /hbase/master got 10.104.37.247:60000
>>>> 2010-10-03 17:40:32,749 INFO
>>>> org.apache.hadoop.hbase.regionserver.HRegionServer: Telling master at
>>>> 10.104.37.247:60000 that we are up
>>>> 2010-10-03 17:40:32,862 INFO
>>>> org.apache.hadoop.hbase.regionserver.ShutdownHook: Installed shutdown hook
>>>> thread: Shutdownhook:regionserver60020
>>>>
>>>> ... and the the master log file just keeps repeating this:
>>>>
>>>> 2010-10-03 17:42:15,531 INFO org.apache.hadoop.hbase.master.ServerManager:
>>>> 0 region servers, 0 dead, average load NaN
>>>> 2010-10-03 17:43:15,541 INFO org.apache.hadoop.hbase.master.ServerManager:
>>>> 0 region servers, 0 dead, average load NaN
>>>>
>>>> After many lines of this sort of thing:
>>>>
>>>> 2010-10-03 17:41:05,179 DEBUG
>>>> org.apache.hadoop.hbase.regionserver.wal.HLog: Split writer thread for
>>>> region
>>>> user,\x01\x88\xFB\xCA,1281914437530.3901f9eb92c049a295aeec3a7e739fe2. got
>>>> 11 to process
>>>> 2010-10-03 17:41:05,180 DEBUG
>>>> org.apache.hadoop.hbase.regionserver.wal.HLog: Split writer thread for
>>>> region
>>>> user,\x01\x88\xFB\xCA,1281914437530.3901f9eb92c049a295aeec3a7e739fe2.
>>>> Applied 11 total edits to
>>>> user,\x01\x88\xFB\xCA,1281914437530.3901f9eb92c049a295ae
>>>>
>>>> Followed by many lines of this:
>>>>
>>>> 2010-10-03 17:41:24,719 DEBUG
>>>> org.apache.hadoop.hbase.regionserver.wal.HLog: Closed
>>>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/user/7b49d357be708d07e6f01843a35286a7/recovered.edits/0000000000075377494
>>>> 2010-10-03 17:41:24,724 DEBUG
>>>> org.apache.hadoop.hbase.regionserver.wal.HLog: Closed
>>>> hdfs://domU-12-31-39-03-44-F1.compute-1.internal:9000/hbase/user/3a58b7adcf049800be83425e75288eeb/recovered.edits/0000000000075377495
>>>>
>>>> As one might expect, attempts to achbase hang, for example:
>>>>
>>>> HBase Shell; enter 'help<RETURN>' for list of supported commands.
>>>> Type "exit<RETURN>" to leave the HBase Shell
>>>> Version: 0.89.20100924, r1001068, Fri Sep 24 13:55:42 PDT 2010
>>>>
>>>> hbase(main):001:0> list
>>>> TABLE
>>>>
>>>>
>>>> I'm using CDH3b2 for hdfs and the version of hbase from here:
>>>> http://people.apache.org/~jdcryans/hbase-0.89.20100924-candidate-1
>>>>
>>>> Any ideas on how I can get the master to recognize the region servers?
>>>> I'm really just concerned with how to get back up and running.
>>>>
>>>> Thank you
>>>>
>>>> Matthew
>>>>
>>>>
>>
>
