Thanks for your reply. I understand your mean.
But It is not enough.
This is log.
Hmaster log:
2011-05-23 10:56:17,326 INFO org.apache.hadoop.hbase.master.ServerManager:
Waiting on regionserver(s) to checkin
2011-05-23 10:56:18,393 INFO org.apache.hadoop.hbase.master.ServerManager:
Registering server=158-1-101-222,20020,1306119315097, regionCount=0,
userLoad=false
2011-05-23 10:56:18,826 INFO org.apache.hadoop.hbase.master.ServerManager:
Waiting on regionserver(s) count to settle; currently=1
2011-05-23 10:56:20,326 INFO org.apache.hadoop.hbase.master.ServerManager:
Finished waiting for regionserver count to settle; count=1, sleptFor=19500
2011-05-23 10:56:20,326 INFO org.apache.hadoop.hbase.master.ServerManager:
Exiting wait on regionserver(s) to checkin; count=1, stopped=false, count of
regions out on cluster=0
2011-05-23 10:56:20,329 INFO org.apache.hadoop.hbase.master.MasterFileSystem:
Log folder
hdfs://158.1.101.82:9000/hbase/.logs/158-1-101-222,20020,1306111562081 doesn't
belong to a known region server, splitting
2011-05-23 10:56:20,341 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 2 hlog(s) in
hdfs://158.1.101.82:9000/hbase/.logs/158-1-101-222,20020,1306111562081
2011-05-23 10:56:20,342 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-0,5,main]: starting
.......
2011-05-23 10:56:25,152 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split writer
threads to finish
2011-05-23 10:56:25,983 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers finished
2011-05-23 10:56:25,983 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file splitting
completed in 2004 ms for
hdfs://158.1.101.82:9000/hbase/.logs/158-1-101-82,20020,1306117051387
2011-05-23 10:56:29,032 WARN
org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
RemoteException connecting to RS
org.apache.hadoop.ipc.RemoteException:
org.apache.hadoop.hbase.ipc.ServerNotRunningException: Server is not running yet
at
org.apache.hadoop.hbase.master.HMaster.assignRootAndMeta(HMaster.java:431)
at
org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:389)
at org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:283)
2011-05-23 10:56:29,034 INFO
org.apache.hadoop.hbase.catalog.RootLocationEditor: Unsetting ROOT region
location in ZooKeeper
2011-05-23 10:56:29,058 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Creating (or
updating) unassigned node for 70236052 with OFFLINE state
2011-05-23 10:56:29,071 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
No previous transition plan was found (or we are ignoring an existing plan) for
-ROOT-,,0.70236052 so generated a random one; hri=-ROOT-,,0.70236052, src=,
dest=158-1-101-222,20020,1306119315097; 1 (online=1, exclude=null) available
servers
2011-05-23 10:56:29,071 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Assigning region -ROOT-,,0.70236052 to 158-1-101-222,20020,1306119315097
2011-05-23 10:56:29,071 DEBUG org.apache.hadoop.hbase.master.ServerManager: New
connection to 158-1-101-222,20020,1306119315097
2011-05-23 10:56:29,095 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Handling transition=RS_ZK_REGION_OPENING,
server=158-1-101-222,20020,1306119315097, region=70236052/-ROOT-
2011-05-23 10:56:29,208 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Handling transition=RS_ZK_REGION_OPENING,
server=158-1-101-222,20020,1306119315097, region=70236052/-ROOT-
2011-05-23 10:56:29,220 INFO org.apache.hadoop.hbase.master.HMaster: -ROOT-
assigned=1, rit=false, location=158-1-101-222:20020
2011-05-23 10:56:29,233 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Handling transition=RS_ZK_REGION_OPENED,
server=158-1-101-222,20020,1306119315097, region=70236052/-ROOT-
2011-05-23 10:56:29,236 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
event for 70236052; deleting unassigned node
2011-05-23 10:56:29,236 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Deleting
existing unassigned node for 70236052 that is in expected state
RS_ZK_REGION_OPENED
2011-05-23 10:56:29,245 INFO org.apache.hadoop.hbase.catalog.CatalogTracker:
Failed verification of .META.,,1 at address=null;
org.apache.hadoop.hbase.NotServingRegionException:
org.apache.hadoop.hbase.NotServingRegionException: Region is not online:
.META.,,1
2011-05-23 10:56:29,245 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Creating (or
updating) unassigned node for 1028785192 with OFFLINE state
2011-05-23 10:56:29,252 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Successfully
deleted unassigned node for region 70236052 in expected state
RS_ZK_REGION_OPENED
2011-05-23 10:56:29,254 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region
-ROOT-,,0.70236052 on 158-1-101-222,20020,1306119315097
2011-05-23 10:56:29,263 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Handling transition=M_ZK_REGION_OFFLINE, server=158-1-101-222:20000,
region=1028785192/.META.
2011-05-23 10:56:29,263 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
No previous transition plan was found (or we are ignoring an existing plan) for
.META.,,1.1028785192 so generated a random one; hri=.META.,,1.1028785192, src=,
dest=158-1-101-222,20020,1306119315097; 1 (online=1, exclude=null) available
servers
2011-05-23 10:56:29,263 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Assigning region .META.,,1.1028785192 to 158-1-101-222,20020,1306119315097
2011-05-23 10:56:29,278 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Handling transition=RS_ZK_REGION_OPENING,
server=158-1-101-222,20020,1306119315097, region=1028785192/.META.
2011-05-23 10:56:30,682 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Handling transition=RS_ZK_REGION_OPENING,
server=158-1-101-222,20020,1306119315097, region=1028785192/.META.
2011-05-23 10:56:30,711 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Handling transition=RS_ZK_REGION_OPENED,
server=158-1-101-222,20020,1306119315097, region=1028785192/.META.
2011-05-23 10:56:30,712 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
event for 1028785192; deleting unassigned node
2011-05-23 10:56:30,712 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Deleting
existing unassigned node for 1028785192 that is in expected state
RS_ZK_REGION_OPENED
2011-05-23 10:56:30,719 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Successfully
deleted unassigned node for region 1028785192 in expected state
RS_ZK_REGION_OPENED
2011-05-23 10:56:30,719 DEBUG
org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region
.META.,,1.1028785192 on 158-1-101-222,20020,1306119315097
2011-05-23 10:56:30,719 INFO org.apache.hadoop.hbase.zookeeper.MetaNodeTracker:
Detected completed assignment of META, notifying catalog tracker
2011-05-23 10:56:30,726 INFO org.apache.hadoop.hbase.master.HMaster: .META.
assigned=2, rit=false, location=158-1-101-222:20020
2011-05-23 10:56:30,726 INFO org.apache.hadoop.hbase.master.HMaster: Master
startup proceeding: cluster startup
2011-05-23 10:56:30,726 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Deleting any
existing unassigned nodes
// regionserver(158-1-101-82) Registered
2011-05-23 10:56:33,504 INFO org.apache.hadoop.hbase.master.ServerManager:
Registering server=158-1-101-82,20020,1306117051387, regionCount=1344,
userLoad=true
2011-05-23 10:56:33,875 INFO org.apache.hadoop.hbase.master.AssignmentManager:
Bulk assigning 5041 region(s) across 1 server(s), retainAssignment=true
2011-05-23 10:56:33,876 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Timeout-on-RIT=5041000
//regions was opened in 158-1-101-222 machine
2011-05-23 10:56:33,876 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
Bulk assigning 5041 region(s) to 158-1-101-222,20020,1306119315097
2011-05-23 10:56:33,935 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for b18eba004dfe6b1224f16a275ec342d1 with OFFLINE state
2011-05-23 10:56:33,935 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for 43b4b419baec6114a9afbc1432d17856 with OFFLINE state
2011-05-23 10:56:33,935 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for 17eb7fc069d11de1d403499caff024e4 with OFFLINE state
2011-05-23 10:56:33,935 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for ef4ec24ce49e31ec2c5c51a4acc76e4e with OFFLINE state
2011-05-23 10:56:33,935 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for 86e6193a18c887a2ebcaf7c409ac7c5f with OFFLINE state
2011-05-23 10:56:33,935 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for 5f81b6cecf483f0f8b26fce5b7040078 with OFFLINE state
2011-05-23 10:56:33,936 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for faf9d38383ac7d8d594743e8aee400e3 with OFFLINE state
2011-05-23 10:56:33,936 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for 52a547b878ca41dc1a6fbf84800bf1c3 with OFFLINE state
2011-05-23 10:56:33,936 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for cfb4d5cacedb5f6d21e332c533634338 with OFFLINE state
2011-05-23 10:56:33,936 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Async create
of unassigned node for 3e332c1a428fa51ade3ac3fbe5dfee50 with OFFLINE state
-----邮件原件-----
发件人: Ted Yu [mailto:[email protected]]
发送时间: 2011年5月26日 19:37
收件人: [email protected]
主题: Re: About RegionServer checkin
Do you see the following message in master log for 158-1-101-82 ?
String message = "Server " + what + " rejected; currently processing "
+
serverName + " as dead server";
Thanks
On Thu, May 26, 2011 at 4:29 AM, Ted Yu <[email protected]> wrote:
> This was from 158-1-101-82 log, right ?
>
> >> 2011-05-23 10:21:37,400 DEBUG org.apache.hadoop.hbase.
> regionserver.handler.OpenRegionHandler: Opened
> hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>
> Can you paste more log before the above line ?
> Master log around 2011-05-23 10:21:37,400 would help too.
>
>
> On Thu, May 26, 2011 at 2:35 AM, Gaojinchao <[email protected]> wrote:
>
>> Sorry, I hate my poor English .
>>
>> I give a description again:
>> Master add regionserver to onlineServers in two case:
>> 1. Add a machine to the cluster, It includes cluster startup or add a new
>> machine.
>> Master can get region server information from api "regionServerStartup"
>> and add to onlineServers set.
>>
>> 2. Master is restarted.
>> Master can get region server information from api "regionServerReport" and
>> add to onlineServers set.
>> But It must be happened when Master called function
>> waitForRegionServers().
>> If region sever reported is later, Master will take it for a dead server.
>> The regions will be assigned.
>> So one region is opened in different region server.
>>
>> I think the later region server should shutdown itself and start again. It
>> can register by api regionServerStartup
>> But not api regionServerReport
>>
>> eg: region could not be assigned by balance
>>
>> Hmaster logs:
>> 2011-05-23 11:12:10,588 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
>> hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. to
>> 158-1-101-82,20020,1306117051387
>> 2011-05-23 11:15:20,472 INFO
>> org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition
>> timed out: hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> state=PENDING_OPEN, ts=1306120330588
>> 2011-05-23 11:15:20,472 INFO
>> org.apache.hadoop.hbase.master.AssignmentManager: Region has been
>> PENDING_OPEN for too long, reassigning
>> region=hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:15:20,513 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE;
>> was=hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> state=PENDING_OPEN, ts=1306120330588
>> 2011-05-23 11:15:20,513 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: No previous transition
>> plan was found (or we are ignoring an existing plan) for
>> hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. so generated a
>> random one;
>> hri=hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d., src=,
>> dest=158-1-101-82,20020,1306117051387; 2 (online=2, exclude=null) available
>> servers
>> 2011-05-23 11:15:20,513 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
>> hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. to
>> 158-1-101-82,20020,1306117051387
>> 2011-05-23 11:18:30,473 INFO
>> org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition
>> timed out: hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> state=PENDING_OPEN, ts=1306120520513
>> 2011-05-23 11:18:30,473 INFO
>> org.apache.hadoop.hbase.master.AssignmentManager: Region has been
>> PENDING_OPEN for too long, reassigning
>> region=hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:18:30,487 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE;
>> was=hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> state=PENDING_OPEN, ts=1306120520513
>> 2011-05-23 11:18:30,487 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: No previous transition
>> plan was found (or we are ignoring an existing plan) for
>> hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. so generated a
>> random one;
>> hri=hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d., src=,
>> dest=158-1-101-222,20020,1306119315097; 2 (online=2, exclude=null) available
>> servers
>> 2011-05-23 11:18:30,488 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
>> hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. to
>> 158-1-101-222,20020,1306119315097
>> 2011-05-23 11:18:30,516 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Handling
>> transition=RS_ZK_REGION_OPENING, server=158-1-101-222,20020,1306119315097,
>> region=70541f0abda274708e12570c52aa7f1d
>> 2011-05-23 11:18:30,581 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Handling
>> transition=RS_ZK_REGION_OPENING, server=158-1-101-222,20020,1306119315097,
>> region=70541f0abda274708e12570c52aa7f1d
>> 2011-05-23 11:18:30,900 DEBUG
>> org.apache.hadoop.hbase.master.AssignmentManager: Handling
>> transition=RS_ZK_REGION_OPENED, server=158-1-101-222,20020,1306119315097,
>> region=70541f0abda274708e12570c52aa7f1d
>> 2011-05-23 11:18:30,900 DEBUG
>> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
>> event for 70541f0abda274708e12570c52aa7f1d; deleting unassigned node
>> 2011-05-23 11:18:30,900 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
>> master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006 Deleting
>> existing unassigned node for 70541f0abda274708e12570c52aa7f1d that is in
>> expected state RS_ZK_REGION_OPENED
>> 2011-05-23 11:18:30,930 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
>> master:20000-0x2301a9c63bd0006-0x2301a9c63bd0006-0x2301a9c63bd0006
>> Successfully deleted unassigned node for region
>> 70541f0abda274708e12570c52aa7f1d in expected state RS_ZK_REGION_OPENED
>>
>>
>> Regionserver logs:
>> 2011-05-23 10:21:37,400 DEBUG
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened
>> hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:04:19,633 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
>> region: hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:04:19,633 DEBUG
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:04:19,633 WARN
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Attempted
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. but
>> already online on this server
>> 2011-05-23 11:09:00,615 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
>> region: hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:09:00,615 DEBUG
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:09:00,615 WARN
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Attempted
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. but
>> already online on this server
>> 2011-05-23 11:12:10,588 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
>> region: hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:12:10,588 DEBUG
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:12:10,588 WARN
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Attempted
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. but
>> already online on this server
>> 2011-05-23 11:15:20,513 INFO
>> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
>> region: hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:15:20,513 DEBUG
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d.
>> 2011-05-23 11:15:20,513 WARN
>> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Attempted
>> open of hello,150900,1305944335445.70541f0abda274708e12570c52aa7f1d. but
>> already online on this server
>>
>
>
