You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-dev@hadoop.apache.org by "stack (JIRA)" <ji...@apache.org> on 2007/11/28 00:28:43 UTC

[jira] Created: (HADOOP-2295) [hbase] Still multi-assigning regions

[hbase] Still multi-assigning regions
-------------------------------------

                 Key: HADOOP-2295
                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
             Project: Hadoop
          Issue Type: Bug
          Components: contrib/hbase
            Reporter: stack
            Priority: Minor


Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.

Here is master log:

{code}
...
2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
...
{code}

Here is regionserver log on node XX.XX.XX.33:

{code}
...
2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
..
{code}


It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Hudson (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12547104 ] 

Hudson commented on HADOOP-2295:
--------------------------------

Integrated in Hadoop-Nightly #318 (See [http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Nightly/318/])

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Status: Open  (was: Patch Available)

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12546087 ] 

Jim Kellerman commented on HADOOP-2295:
---------------------------------------

We figured out a likely scenario for how this could happen.

 1. master assigns region to a region server
 2. region server puts open region on its 'todo list' 
  - todo list executes in a separate thread because actions on the todo list may take longer than a heartbeat interval to complete.
 3. region server is still processing todo list when it is time to send a heartbeat to the master
 4. master assigns the same region to the server because it is still unassigned and no region server is serving it
 5. region server completes bringing region on-line and tells the master in the next heartbeat message
 6. master replies saying "Ive assigned this region to someone else. close it and don't tell me you've closed it.
 7. region server queues close request and this stops the region from coming online.
 8. master thinks region server should be serving the region so it is removed from unassigned regions list.
 9. no region server ends up serving the region even though the master thinks it is not an unserved region

To fix this we propose that when the master assigns a region it puts the region in a delay queue with a timeout of 2 * lease interval.
If the region server responds in 2 * lease interval saying it is serving the region, then the master finishes processing the event of the region coming online.
If the region server does not respond in 2 * lease interval that it is serving the region, the master assumes that either:
- the region server has died and will never serve the region
- the region server never got the message to serve the region
and consequently will assign the region to the next appropriate region server.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>            Reporter: stack
>            Priority: Minor
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Assigned: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman reassigned HADOOP-2295:
-------------------------------------

    Assignee: Jim Kellerman

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>            Reporter: stack
>            Assignee: Jim Kellerman
>            Priority: Minor
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Hadoop QA (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12546852 ] 

Hadoop QA commented on HADOOP-2295:
-----------------------------------

+1 overall.  Here are the results of testing the latest attachment 
http://issues.apache.org/jira/secure/attachment/12370566/patch.txt
against trunk revision r599447.

    @author +1.  The patch does not contain any @author tags.

    javadoc +1.  The javadoc tool did not generate any warning messages.

    javac +1.  The applied patch does not generate any new compiler warnings.

    findbugs +1.  The patch does not introduce any new Findbugs warnings.

    core tests +1.  The patch passed core unit tests.

    contrib tests +1.  The patch passed contrib unit tests.

Test results: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1206/testReport/
Findbugs warnings: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1206/artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
Checkstyle results: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1206/artifact/trunk/build/test/checkstyle-errors.html
Console output: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1206/console

This message is automatically generated.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Attachment: patch.txt

Clean up some shut down code.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Attachment: patch.txt

Address race condition between main processing loop and meta/root scanners.

May also fix HADOOP-2303

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "stack (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12546267 ] 

stack commented on HADOOP-2295:
-------------------------------

The sense is that this issue has been around for a long time and that it has been responsible for profusion of unexplainable NotServerRegionExceptions.

Whats happening is that the master double-assigns a region.  Because of the context at the time of assignment hasn't changed when the second assignment happens, the two assignments go to the same host.  When the first assignment reports back to the master that region is open, because of the state in the master, it thinks it a rogue regionserver coming up deploying regions it shouldn't have.  So the master sends a 'you-shouldn't-have-opened-that-region-shut-it-down' message.  Regionserver dutifully closes the region.  As far as the master is concerned, its accounting shows the region properly assigned though no regionserver is now carrying the region.  Clients come in looking for a row from the problematic region.  Master sends them to where it thinks the region has been deployed.  When client goes to identified regionserver, it throws the NotServingRegionException.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>            Reporter: stack
>            Priority: Minor
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Attachment: patch.txt

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Priority: Major  (was: Minor)

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>            Reporter: stack
>            Assignee: Jim Kellerman
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Hadoop QA (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12546599 ] 

Hadoop QA commented on HADOOP-2295:
-----------------------------------

-1 overall.  Here are the results of testing the latest attachment 
http://issues.apache.org/jira/secure/attachment/12370498/patch.txt
against trunk revision r599223.

    @author +1.  The patch does not contain any @author tags.

    javadoc +1.  The javadoc tool did not generate any warning messages.

    javac +1.  The applied patch does not generate any new compiler warnings.

    findbugs +1.  The patch does not introduce any new Findbugs warnings.

    core tests +1.  The patch passed core unit tests.

    contrib tests -1.  The patch failed contrib unit tests.

Test results: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1198/testReport/
Findbugs warnings: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1198/artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
Checkstyle results: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1198/artifact/trunk/build/test/checkstyle-errors.html
Console output: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1198/console

This message is automatically generated.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Status: Open  (was: Patch Available)

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

        Fix Version/s: 0.16.0
    Affects Version/s: 0.16.0
               Status: Patch Available  (was: Open)

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Status: Patch Available  (was: Open)

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12546440 ] 

Jim Kellerman commented on HADOOP-2295:
---------------------------------------

When the master assigned a region twice to the same server, what happened was that on the second assignment, the region server returned two 'region is opened' messages in the same message to the master (code bug in HRegionServer). The first message was processed properly and the master queued a task to update the meta. The master then looped to process the second message, and now the region was no longer in the 'unassigned regions' list so the master told the region server to close it. In the mean time, the update of the meta completes, clients start trying to access the region but the region server has closed the region so the client gets a NotServingRegion exception.

The master was doing the 'right thing' by reassigning the region because the region server took longer than 'hbase.hbasemaster.maxregionopen' (30 seconds) to open the region.

Fixing the aforementioned bug will prevent this from occurring, but if the master should assign the same region to two different region servers, this could easily result in corrupting the region beyond repair as there is a lot of file i/o associated with bringing a region on-line. To avoid this, we propose that a region server acknowledge that it is opening the region, and when the master receives the ack, it extends the region reassignment timeout. If the region server subsequently fails to open the region, the master can reassign the region after the additional grace period and we can be pretty certain that there will be no interference between multiple region servers opening the same region.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>            Reporter: stack
>            Assignee: Jim Kellerman
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Status: Patch Available  (was: Open)

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Hadoop QA (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12546546 ] 

Hadoop QA commented on HADOOP-2295:
-----------------------------------

-1 overall.  Here are the results of testing the latest attachment 
http://issues.apache.org/jira/secure/attachment/12370479/patch.txt
against trunk revision r599223.

    @author +1.  The patch does not contain any @author tags.

    javadoc +1.  The javadoc tool did not generate any warning messages.

    javac +1.  The applied patch does not generate any new compiler warnings.

    findbugs +1.  The patch does not introduce any new Findbugs warnings.

    core tests -1.  The patch failed core unit tests.

    contrib tests -1.  The patch failed contrib unit tests.

Test results: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1195/testReport/
Findbugs warnings: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1195/artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
Checkstyle results: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1195/artifact/trunk/build/test/checkstyle-errors.html
Console output: http://lucene.zones.apache.org:8080/hudson/job/Hadoop-Patch/1195/console

This message is automatically generated.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (HADOOP-2295) [hbase] Still multi-assigning regions

Posted by "Jim Kellerman (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-2295?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jim Kellerman updated HADOOP-2295:
----------------------------------

    Resolution: Fixed
        Status: Resolved  (was: Patch Available)

Tests passed. Committed.

> [hbase] Still multi-assigning regions
> -------------------------------------
>
>                 Key: HADOOP-2295
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2295
>             Project: Hadoop
>          Issue Type: Bug
>          Components: contrib/hbase
>    Affects Versions: 0.16.0
>            Reporter: stack
>            Assignee: Jim Kellerman
>             Fix For: 0.16.0
>
>         Attachments: patch.txt, patch.txt, patch.txt
>
>
> Start key is img216/1725/22236401lvh6.gif.  We doubly assign.  In between assignments, master rules 'should not have opened region' and sends a shutdown region to remote server -- which it obeys. Meantime, master thinks regions are deployed.
> Here is master log:
> {code}
> ...
> 2007-11-27 04:26:21,818 INFO  hbase.HMaster - region postlog,img216/1725/22236401lvh6.gif,1196164441230 split. New regions are: postlog,img216/1725/22236401lvh6.gif,1196166373235, postlog,img216/3961/aasaxonlivene6.jpg,1196166373241
> 2007-11-27 04:26:23,261 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:26:27,462 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -400573094926830852 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: , startCode: -1
> 2007-11-27 04:26:27,464 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:26:27,671 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:26:53,328 INFO  hbase.HMaster - assigning region postlog,img216/1725/22236401lvh6.gif,1196166373235 to server XX.XX.XX.33:60020
> 2007-11-27 04:27:05,364 INFO  hbase.HMaster - XX.XX.XX.33:60020 serving postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,364 DEBUG hbase.HMaster - region server XX.XX.XX.33:60020 should not have opened region postlog,img216/1725/22236401lvh6.gif,1196166373235
> 2007-11-27 04:27:05,367 INFO  hbase.HMaster - regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}} open on XX.XX.XX.33:60020
> 2007-11-27 04:27:05,368 INFO  hbase.HMaster - updating row postlog,img216/1725/22236401lvh6.gif,1196166373235 in table .META.,,1 with startcode 1196155493271 and server XX.XX.XX.33:60020
> 2007-11-27 04:27:26,380 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -4876467680083821318 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:27:26,381 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:27:26,511 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:28:26,444 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1725/22236401lvh6.gif>, offline: true, split: true, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.25:60020, startCode: 1196155489036
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - HMaster.metaScanner scanner: -7699450087241029374 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}}, server: XX.XX.XX.33:60020, startCode: 1196155493271
> 2007-11-27 04:28:26,446 DEBUG hbase.HMaster - Checking postlog,img216/1725/22236401lvh6.gif,1196166373235 is assigned
> 2007-11-27 04:28:26,590 DEBUG hbase.HMaster - Checked postlog,img216/1725/22236401lvh6.gif,1196164441230 for references: splitA: true, splitB: true
> 2007-11-27 04:29:26,459 DEBUG hbase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 regioninfo: {regionname: postlog,img216/1725/22236401lvh6.gif,1196164441230, startKey: <img216/1401lvh6.gif>, offline: true, split: true, tableDesc: {name: po: 1, compression: NONE, in memory: false, max length: 21474836s: 1, compression: NONE, in memory: false, max length: 21474836er: none}}}}, server: XX.XX.XX.25:60020, startCode: 11961554890ase.HMaster - HMaster.metaScanner scanner: 5846860608957952540 /1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22okie:={name: cookie, max versions: 1, compression: NONE, in mem NONE, in memory: false, max length: 2147483647, bloom filter: artCode: 1196155493271
> 2007-11-27 04:29:26,461 DEBUG hbase.HMas235 is assigned
> 2007-11-27 04:29:26,622 DEBUG hbase.HMaster - Cces: splitA: true, splitB: true
> ...
> {code}
> Here is regionserver log on node XX.XX.XX.33:
> {code}
> ...
> 2007-11-27 04:26:29,318 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:26:29,325 DEBUG hbase.HStore - starting 51396220/cookie (no reconstruction log)
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegionServer - flushing region postlog,img100/941/brandyfn6.gif,1196158363481
> 2007-11-27 04:26:30,420 DEBUG hbase.HRegion - Not flushing cache for region postlog,img100/941/brandyfn6.gif,1196158363481: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,752 DEBUG hbase.HRegionServer - flushing region postlog,img149/2019/liyanaum6.gif,1196164996321
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/2019/liyanaum6.gif,1196164996321: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegionServer - flushing region postlog,img148/6048/p9290339kb0.jpg,1196162613173
> 2007-11-27 04:26:31,753 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/6048/p9290339kb0.jpg,1196162613173: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegionServer - flushing region postlog,img132/5512/timeline8bx.png,1196159744555
> 2007-11-27 04:26:31,754 DEBUG hbase.HRegion - Not flushing cache for region postlog,img132/5512/timeline8bx.png,1196159744555: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegionServer - flushing region postlog,img149/3724/whosherne4.jpg,1196164996322
> 2007-11-27 04:26:37,915 DEBUG hbase.HRegion - Not flushing cache for region postlog,img149/3724/whosherne4.jpg,1196164996322: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:26:57,059 DEBUG hbase.HRegionServer - flushing region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439
> 2007-11-27 04:26:57,060 DEBUG hbase.HRegion - Not flushing cache for region postlog,img148/8339/361de8578d356flip0hd.png,1196165445439: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:03,604 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/cookie is 30625781
> 2007-11-27 04:27:03,761 DEBUG hbase.HStore - starting 51396220/ip (no reconstruction log)
> 2007-11-27 04:27:03,859 DEBUG hbase.HStore - maximum sequence id for hstore 51396220/ip is 30625781
> 2007-11-27 04:27:03,965 DEBUG hbase.HRegion - Next sequence id for region postlog,img216/1725/22236401lvh6.gif,1196166373235 is 30625782
> 2007-11-27 04:27:03,969 INFO  hbase.HRegion - region postlog,img216/1725/22236401lvh6.gif,1196166373235 available
> 2007-11-27 04:27:03,969 INFO  hbase.HRegionServer - MSG_REGION_OPEN : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 INFO  hbase.HRegionServer - MSG_REGION_CLOSE_WITHOUT_REPORT : regionname: postlog,img216/1725/22236401lvh6.gif,1196166373235, startKey: <img216/1725/22236401lvh6.gif>, tableDesc: {name: postlog, families: {cookie:={name: cookie, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}, ip:={name: ip, max versions: 1, compression: NONE, in memory: false, max length: 2147483647, bloom filter: none}}}
> 2007-11-27 04:27:04,578 DEBUG hbase.HRegion - Not flushing cache for region postlog,img216/1725/22236401lvh6.gif,1196166373235: snapshotMemcaches() determined that there was nothing to do
> 2007-11-27 04:27:04,579 DEBUG hbase.HStore - closed 51396220/ip
> 2007-11-27 04:27:04,580 DEBUG hbase.HStore - closed 51396220/cookie
> 2007-11-27 04:27:04,580 INFO  hbase.HRegion - closed postlog,img216/1725/22236401lvh6.gif,1196166373235
> ..
> {code}
> It looks like the assigned region hasn't been cleared from the unassigned regions list when the report comes in.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.