You are viewing a plain text version of this content. The canonical link for it is here.

Posted to issues@hbase.apache.org by "gaojinchao (JIRA)" <ji...@apache.org> on 2011/08/17 10:26:27 UTC

[jira] [Created] (HBASE-4212) TestMasterFailover fails occasionally

TestMasterFailover fails occasionally
-------------------------------------

                 Key: HBASE-4212
                 URL: https://issues.apache.org/jira/browse/HBASE-4212
             Project: HBase
          Issue Type: Bug
          Components: master
    Affects Versions: 0.90.4
            Reporter: gaojinchao
             Fix For: 0.90.5


It seems a bug. The root in RIT can't be moved..
In the failover process, it enforces root on-line. But not clean zk node. 
test will wait forever.

  void processFailover() throws KeeperException, IOException, InterruptedException {
     
    // we enforce on-line root.
    HServerInfo hsi =
      this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
    regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
    hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
    regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);

It seems that we should wait finished as meta region 
  int assignRootAndMeta()
  throws InterruptedException, IOException, KeeperException {
    int assigned = 0;
    long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);

    // Work on ROOT region.  Is it in zk in transition?
    boolean rit = this.assignmentManager.
      processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
    if (!catalogTracker.verifyRootRegionLocation(timeout)) {
      this.assignmentManager.assignRoot();
      this.catalogTracker.waitForRoot();

      //we need add this code and guarantee that the transition has completed
      this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
      assigned++;
    }

logs:
2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-

//.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
// The test will wait forever.

2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states

2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052


--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13116973#comment-13116973 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

@Ted
Thanks, I don't run it recently. 
I will do it right now and give the result.


                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Updated] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (JIRA)" <ji...@apache.org>.

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

gaojinchao updated HBASE-4212:
------------------------------

    Attachment: HBASE-4212_branch90V1.patch

> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13086202#comment-13086202 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

I test 10 times and logs said that META is assigned after root has finished.

2011-08-17 05:06:51,419 DEBUG [MASTER_OPEN_REGION-C4S2.site:47578-0] zookeeper.ZKUtil(1109): master:47578-0x131d6fe02e50009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,60960,1313571996605, state=RS_ZK_REGION_OPENED
2011-08-17 05:06:51,425 DEBUG [Thread-755-EventThread] zookeeper.ZooKeeperWatcher(252): master:47578-0x131d6fe02e50009 Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/unassigned/70236052
2011-08-17 05:06:51,425 DEBUG [MASTER_OPEN_REGION-C4S2.site:47578-0] zookeeper.ZKAssign(420): master:47578-0x131d6fe02e50009 Successfully deleted unassigned node for region 70236052 in expected state RS_ZK_REGION_OPENED
2011-08-17 05:06:51,426 INFO  [Master:0;C4S2.site:47578] master.HMaster(437): -ROOT- assigned=1, rit=false, location=C4S2.site:60960
2011-08-17 05:06:51,426 DEBUG [MASTER_OPEN_REGION-C4S2.site:47578-0] handler.OpenedRegionHandler(108): Opened region -ROOT-,,0.70236052 on C4S2.site,60960,1313571996605
2011-08-17 05:06:51,427 DEBUG [Master:0;C4S2.site:47578] zookeeper.ZKUtil(553): master:47578-0x131d6fe02e50009 Unable to get data of znode /hbase/unassigned/1028785192 because node does not exist (not an error)
2011-08-17 05:06:51,429 INFO  [Master:0;C4S2.site:47578] catalog.CatalogTracker(421): Passed metaserver is null

> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "Ted Yu (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13116966#comment-13116966 ] 

Ted Yu commented on HBASE-4212:
-------------------------------

@Stack:
Can you take a look at Jinchao's response @ 09/Sep/11 13:57 ?

@Jinchao:
Have you run your patches for test suites of 0.90 and TRUNK recently ?

Thanks
                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13116929#comment-13116929 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

Hi, Does this issue need merge ? 
                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Updated] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (JIRA)" <ji...@apache.org>.

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

gaojinchao updated HBASE-4212:
------------------------------

    Assignee: gaojinchao
      Status: Patch Available  (was: Open)

> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13101213#comment-13101213 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

@Stack， Thanks for your review. 
In our environment, it often fails, so we skip this case(for my case is that all test cases are performed automatically every day). 

The step for opening a root region:
step A: Master tells Region server to open root region.
step B: Region server opens root region and sets zk node(rootServerZNodezk). It is finished means that catalogtracker can works.
step C: Region server updates the zk node(assignmentZNode) tells master that root has opened(some cases may fail, but we have told the root could be used).
step D: Master deletes the zk node (assignmentZNode) and adds root region to online set.

In my case, master skipped the step D because delayed. master forced root region online in processFailover. So zk node couldn't be deleted and failover case failed.

finishInitialization code：
    // Make sure root and meta assigned before proceeding.
    assignRootAndMeta();

    // Is this fresh start with no regions assigned or are we a master joining
    // an already-running cluster?  If regionsCount == 0, then for sure a
    // fresh start.  TOOD: Be fancier.  If regionsCount == 2, perhaps the
    // 2 are .META. and -ROOT- and we should fall into the fresh startup
    // branch below.  For now, do processFailover.
    if (regionCount == 0) {
      LOG.info("Master startup proceeding: cluster startup");
      this.assignmentManager.cleanoutUnassigned();
      this.assignmentManager.assignAllUserRegions();
    } else {
      LOG.info("Master startup proceeding: master failover");
      this.assignmentManager.processFailover();
    }

processFailover code:
    HServerInfo hsi =
      this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
    regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
    hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
    regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);


> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117137#comment-13117137 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

@Ted.
I have analyzed the problem that you said and opened a new issue(https://issues.apache.org/jira/browse/HBASE-4511).
It seems that some data is loss. You can check my analysis.

                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13086199#comment-13086199 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

I have made a patch. Please review it. Thanks.

> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "Ted Yu (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117292#comment-13117292 ] 

Ted Yu commented on HBASE-4212:
-------------------------------

Now that HBASE-4511 has been opened, I vote +1 on Jinchao's patch.
                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "ramkrishna.s.vasudevan (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117176#comment-13117176 ] 

ramkrishna.s.vasudevan commented on HBASE-4212:
-----------------------------------------------

@Ted/@Gao

I think the issue exists in 0.90 branch and not in trunk.  Gao's analysis is valid in 0.90.
In 0.90
{code}
assignRootAndMeta();

    // Is this fresh start with no regions assigned or are we a master joining
    // an already-running cluster?  If regionsCount == 0, then for sure a
    // fresh start.  TOOD: Be fancier.  If regionsCount == 2, perhaps the
    // 2 are .META. and -ROOT- and we should fall into the fresh startup
    // branch below.  For now, do processFailover.
    if (regionCount == 0) {
      LOG.info("Master startup proceeding: cluster startup");
      this.assignmentManager.cleanoutUnassigned();
      this.assignmentManager.assignAllUserRegions();
    } else {
      LOG.info("Master startup proceeding: master failover");
      this.assignmentManager.processFailover();
    }
{code}
Inside AssignmentManager.processFailOver()
{code}
 HServerInfo hsi =
      this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
    regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
    hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
    regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
{code}
we first call regionOnline inside which the region in RIT is getting removed.
So even before the call back happens for OPENED state it is getting removed.  Hence ROOT node remains in RIT and testcase timesout.
In trunk we dont have this problem as in Assignment.joinCluster() we dont have this code of removing from regionOnline.
{code}
    // Scan META to build list of existing regions, servers, and assignment
    // Returns servers who have not checked in (assumed dead) and their regions
    Map<ServerName,List<Pair<HRegionInfo,Result>>> deadServers =
      rebuildUserRegions();
{code}
I will now verify this testcase with the patch with the script in HBASE-4480.  
Gao and Ted what do you suggest?


                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "Hudson (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13118135#comment-13118135 ] 

Hudson commented on HBASE-4212:
-------------------------------

Integrated in HBase-TRUNK #2272 (See [https://builds.apache.org/job/HBase-TRUNK/2272/])
    HBASE-4212  TestMasterFailover fails occasionally (Gao Jinchao)

tedyu : 
Files : 
* /hbase/trunk/CHANGES.txt
* /hbase/trunk/src/main/java/org/apache/hadoop/hbase/master/HMaster.java

                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117145#comment-13117145 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

Version :0.90 

Results :
Tests run: 649, Failures: 0, Errors: 0, Skipped: 1

 T E S T S
-------------------------------------------------------
Running org.apache.hadoop.hbase.master.TestMasterFailover
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 99.09 sec
Results :

Tests run: 4, Failures: 0, Errors: 0, Skipped: 0


                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Updated] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (JIRA)" <ji...@apache.org>.

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

gaojinchao updated HBASE-4212:
------------------------------

    Attachment: HBASE-4212_TrunkV1.patch

> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "gaojinchao (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117188#comment-13117188 ] 

gaojinchao commented on HBASE-4212:
-----------------------------------

I am running all test cases about Trunk. I will give a result tommorrow.

I think Trunk have this problem as well in this case.
1.Master assigns the root 
2.Rs set the root address in zk and then crash before finish opening the root.
3.Master get the root data from zk and start assigning the meta region.
4.Root region is offline and needs be ressigned by monitor timeout.

So I think we need wait the root is removed from RIT. It is safe.


                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Updated] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "ramkrishna.s.vasudevan (Updated) (JIRA)" <ji...@apache.org>.

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

ramkrishna.s.vasudevan updated HBASE-4212:
------------------------------------------

      Resolution: Fixed
    Hadoop Flags: Reviewed
          Status: Resolved  (was: Patch Available)
    
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "Hudson (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13118041#comment-13118041 ] 

Hudson commented on HBASE-4212:
-------------------------------

Integrated in HBase-0.92 #33 (See [https://builds.apache.org/job/HBase-0.92/33/])
    HBASE-4212  TestMasterFailover fails occasionally (Gao Jinchao)

tedyu : 
Files : 
* /hbase/branches/0.92/CHANGES.txt
* /hbase/branches/0.92/src/main/java/org/apache/hadoop/hbase/master/HMaster.java

                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "stack (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13100090#comment-13100090 ] 

stack commented on HBASE-4212:
------------------------------

Gaojinchao.  The patch looks innocuous enough.  Why do you think we need to do the waitForAssignment for root too when we call catalogtracker and ask it wait on root?  Do we need to fix the way catalogtracker works?

Do you see this test failing still?  I took a look at the 0.90 tests up on the apache build and they dont' seem to fail on this test.  

> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "ramkrishna.s.vasudevan (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117979#comment-13117979 ] 

ramkrishna.s.vasudevan commented on HBASE-4212:
-----------------------------------------------

And at the same time even if the check is not there i do not think there will be a problem. Correct me if am wrong.
                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "ramkrishna.s.vasudevan (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117190#comment-13117190 ] 

ramkrishna.s.vasudevan commented on HBASE-4212:
-----------------------------------------------

without the patch i was also able to reproduce the exact problem as Gao reported
                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "Ted Yu (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117851#comment-13117851 ] 

Ted Yu commented on HBASE-4212:
-------------------------------

Integrated to 0.90, 0.92 branches and TRUNK.

Thanks for the patches, Jinchao.

Thanks for the analysis, Ramkrishna.
                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] [Commented] (HBASE-4212) TestMasterFailover fails occasionally

Posted by "ramkrishna.s.vasudevan (Commented) (JIRA)" <ji...@apache.org>.

    [ https://issues.apache.org/jira/browse/HBASE-4212?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13117975#comment-13117975 ] 

ramkrishna.s.vasudevan commented on HBASE-4212:
-----------------------------------------------

Just to add to Gao's comment on 29/Sep/11 09:50
Fix for trunk may not be needed as when the master tries to assign the root
it cant find the root location and hence it will wait for ServerShutdownhandler to assign it .
So it the ServerShutdownHandler that is going to assign the root and not the timeout.
Now adding the check as in 0.90 will not go to till finding the root location whereas it will wait for the ServershutdownHandler to add it to online.

So it is safe to add i feel.

                
> TestMasterFailover fails occasionally
> -------------------------------------
>
>                 Key: HBASE-4212
>                 URL: https://issues.apache.org/jira/browse/HBASE-4212
>             Project: HBase
>          Issue Type: Bug
>          Components: master
>    Affects Versions: 0.90.4
>            Reporter: gaojinchao
>            Assignee: gaojinchao
>             Fix For: 0.90.5
>
>         Attachments: HBASE-4212_TrunkV1.patch, HBASE-4212_branch90V1.patch
>
>
> It seems a bug. The root in RIT can't be moved..
> In the failover process, it enforces root on-line. But not clean zk node. 
> test will wait forever.
>   void processFailover() throws KeeperException, IOException, InterruptedException {
>      
>     // we enforce on-line root.
>     HServerInfo hsi =
>       this.serverManager.getHServerInfo(this.catalogTracker.getMetaLocation());
>     regionOnline(HRegionInfo.FIRST_META_REGIONINFO, hsi);
>     hsi = this.serverManager.getHServerInfo(this.catalogTracker.getRootLocation());
>     regionOnline(HRegionInfo.ROOT_REGIONINFO, hsi);
> It seems that we should wait finished as meta region 
>   int assignRootAndMeta()
>   throws InterruptedException, IOException, KeeperException {
>     int assigned = 0;
>     long timeout = this.conf.getLong("hbase.catalog.verification.timeout", 1000);
>     // Work on ROOT region.  Is it in zk in transition?
>     boolean rit = this.assignmentManager.
>       processRegionInTransitionAndBlockUntilAssigned(HRegionInfo.ROOT_REGIONINFO);
>     if (!catalogTracker.verifyRootRegionLocation(timeout)) {
>       this.assignmentManager.assignRoot();
>       this.catalogTracker.waitForRoot();
>       //we need add this code and guarantee that the transition has completed
>       this.assignmentManager.waitForAssignment(HRegionInfo.ROOT_REGIONINFO);
>       assigned++;
>     }
> logs:
> 2011-08-16 07:45:40,715 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,715 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,715 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,716 INFO  [PostOpenDeployTasks:70236052] catalog.RootLocationEditor(62): Setting ROOT region location in ZooKeeper as C4S2.site:47710
> 2011-08-16 07:45:40,716 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,717 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENING, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> 2011-08-16 07:45:40,725 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(661): regionserver:47710-0x131d2690f780004 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,727 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKUtil(1109): regionserver:47710-0x131d2690f780004 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052; data=region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENING
> 2011-08-16 07:45:40,740 DEBUG [RegionServer:0;C4S2.site,47710,1313495126115-EventThread] zookeeper.ZooKeeperWatcher(252): regionserver:47710-0x131d2690f780004 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [Thread-760-EventThread] zookeeper.ZooKeeperWatcher(252): master:60701-0x131d2690f780009 Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/unassigned/70236052
> 2011-08-16 07:45:40,740 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] zookeeper.ZKAssign(712): regionserver:47710-0x131d2690f780004 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [RS_OPEN_ROOT-C4S2.site,47710,1313495126115-0] handler.OpenRegionHandler(121): Opened -ROOT-,,0.70236052
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:40,741 DEBUG [Thread-760-EventThread] master.AssignmentManager(477): Handling transition=RS_ZK_REGION_OPENED, server=C4S2.site,47710,1313495126115, region=70236052/-ROOT-
> //.............................................It said that zk node can't be cleaned because of we have enforced on-line the root.......................................
> // The test will wait forever.
> 2011-08-16 07:45:40,741 WARN  [Thread-760-EventThread] master.AssignmentManager(540): Received OPENED for region 70236052/-ROOT- from server C4S2.site,47710,1313495126115 but region was in  the state null and not in expected PENDING_OPEN or OPENING states
> 2011-08-16 07:45:41,018 DEBUG [Master:0;C4S2.site:60701] zookeeper.ZKUtil(1109): master:60701-0x131d2690f780009 Retrieved 52 byte(s) of data from znode /hbase/unassigned/70236052 and set watcher; region=-ROOT-,,0, server=C4S2.site,47710,1313495126115, state=RS_ZK_REGION_OPENED
> 2011-08-16 07:45:41,233 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,337 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,439 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,543 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,645 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,748 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:41,900 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,002 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,105 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,206 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,308 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052
> 2011-08-16 07:45:42,410 DEBUG [Thread-760] zookeeper.ZKAssign(807): ZK RIT -> 70236052

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira