You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by "Haijun Cao (JIRA)" <ji...@apache.org> on 2009/07/22 00:39:15 UTC
[jira] Commented: (HBASE-1681) NSRE due to duplicate assignment to
the same region server
[ https://issues.apache.org/jira/browse/HBASE-1681?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12733870#action_12733870 ]
Haijun Cao commented on HBASE-1681:
-----------------------------------
In summary, this is the event sequence that lead to NSRE for region TestTable,0001724032,1248204794507:
1 master assign to snv-it-lin-011
2 master complain that the assignment is invalid
3 master assign to snv-it-lin-011 (again?)
4 region is opened in snv-it-lin-011
5 region is opened in snv-it-lin-011 again, region server decide to close the region (without report to master) due to duplicate assignment.
The workaround is to delete '.META.','TestTable,0001724032,1248204794507','info:server'
to force master to assign the region again.
> NSRE due to duplicate assignment to the same region server
> ----------------------------------------------------------
>
> Key: HBASE-1681
> URL: https://issues.apache.org/jira/browse/HBASE-1681
> Project: Hadoop HBase
> Issue Type: Bug
> Components: master
> Affects Versions: 0.20.0
> Environment: Software
> * hbase trunk (0.20.0-dev, r795916)
> * hadoop-0.20.0
> * zookeeper-3.2.0
> Hardware
> * 3 dev servers: 8 core, 16G ram, 4x750G 7200 rpm SATA disk, RAID 0, each disk individually mounted
> * snv-it-lin-010:
> o hadoop namenode (1G)
> o hadoop secondary namenode (1G)
> o hadoop datanode (1G, max_xreciver=4096, handler=50)
> o hadoop job track (1G)
> o hadoop taks tracker (1G, max_map=1, max_red=1)
> o zookeeper (1G)
> o hbase master (2G)
> o hbase region server (2G)
> * snv-it-lin-011:
> o hadoop datanode (1G, max_xreciver=4096, handler=50)
> o hadoop taks tracker (1G, max_map=1, max_red=1)
> o zookeeper (1G)
> o hbase region server (2G, handler=50)
> * snv-it-lin-012:
> o hadoop datanode (1G, max_xreciver=4096, handler=50)
> o hadoop taks tracker (1G, max_map=1, max_red=1)
> o zookeeper (1G)
> o hbase region server (2G, handler=50)
> * jvm: 32bit
>
> Reporter: Haijun Cao
>
> Reproduce:
> 1. populate hbase with 100 m records: bin/hadop jar hbase-dev-test.jar --rows=1000000 sequtialWrite 100
> 2. populate hbase with 10 m records (random writes): bin/hadoop jar hbase-dev-test.jar --rows=1000000 randomWrite 10
> 3. scan 10 m records: bin/hadoop jar hbase-dev-test.jar --rows=1000000 scan 10
> 2 scan mapper task failed with NSRE exception for one region:
> org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: TestTable,0001724032,1248204794507
> at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2251)
> at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1862)
> at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
> at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:913)
> Grep master log for TestTable,0001724032,1248204794507:
> 2009-07-21 12:33:18,275 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_SPLIT: TestTable,0001724032,1248141721258: Daughters; TestTable,0
> 001724032,1248204794507, TestTable,0001780000,1248204794507 from snv-it-lin-010.
> projectrialto.com,60020,1248115451722; 1 of 3
> 2009-07-21 12:33:19,169 INFO org.apache.hadoop.hbase.master.RegionManager: Assig
> ning region TestTable,0001724032,1248204794507 to snv-it-lin-011.projectrialto.c
> om,60020,1248115452051
> 2009-07-21 12:33:21,464 DEBUG org.apache.hadoop.hbase.master.BaseScanner: Curren
> t assignment of TestTable,0001724032,1248204794507 is not valid; Server '' star
> tCode: 0 unknown.
> 2009-07-21 12:33:22,207 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_PROCESS_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-
> 011.projectrialto.com,60020,1248115452051; 1 of 1
> 2009-07-21 12:33:22,208 INFO org.apache.hadoop.hbase.master.RegionManager: Assig
> ning region TestTable,0001724032,1248204794507 to snv-it-lin-011.projectrialto.c
> om,60020,1248115452051
> 2009-07-21 12:33:25,245 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_PROCESS_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-
> 011.projectrialto.com,60020,1248115452051; 1 of 3
> 2009-07-21 12:33:25,245 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_PROCESS_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-
> 011.projectrialto.com,60020,1248115452051; 3 of 3
> 2009-07-21 12:33:28,283 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_PROCESS_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-
> 011.projectrialto.com,60020,1248115452051; 1 of 7
> 2009-07-21 12:33:28,283 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_PROCESS_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-
> 011.projectrialto.com,60020,1248115452051; 3 of 7
> 2009-07-21 12:33:28,283 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-011.proj
> ectrialto.com,60020,1248115452051; 5 of 7
> 2009-07-21 12:33:28,284 INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-011.proj
> ectrialto.com,60020,1248115452051; 5 of 7
> 2009-07-21 12:33:28,284 INFO org.apache.hadoop.hbase.master.ServerManager: Recei
> ved MSG_REPORT_OPEN: TestTable,0001724032,1248204794507 from snv-it-lin-011.proj
> ectrialto.com,60020,1248115452051; 7 of 7
> 2009-07-21 12:33:28,284 DEBUG org.apache.hadoop.hbase.master.ServerManager: regi
> on server 10.10.30.105:60020 should not have opened region TestTable,0001724032,
> 1248204794507
> 2009-07-21 12:33:28,289 INFO org.apache.hadoop.hbase.master.RegionServerOperatio
> n: TestTable,0001724032,1248204794507 open on 10.10.30.105:60020
> 2009-07-21 12:33:28,289 INFO org.apache.hadoop.hbase.master.RegionServerOperatio
> n: updating row TestTable,0001724032,1248204794507 in region .META.,,1 with star
> tcode 1248115452051 and server 10.10.30.105:60020
> Grep region server log for TestTable,0001724032,1248204794507:
> 2009-07-21 12:33:19,163 INFO org.apache.hadoop.hbase.regionserver.HRegionServer:
> MSG_REGION_OPEN: TestTable,0001724032,1248204794507
> 2009-07-21 12:33:22,202 INFO org.apache.hadoop.hbase.regionserver.HRegionServer:
> MSG_REGION_OPEN: TestTable,0001724032,1248204794507
> 2009-07-21 12:33:26,183 INFO org.apache.hadoop.hbase.regionserver.HRegionServer:
> Worker: MSG_REGION_OPEN: TestTable,0001724032,1248204794507
> 2009-07-21 12:33:26,184 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Open
> ing region TestTable,0001724032,1248204794507, encoded=3313355
> 2009-07-21 12:33:26,204 INFO org.apache.hadoop.hbase.regionserver.HRegion: regio
> n TestTable,0001724032,1248204794507/3313355 available; sequence id is 45707088
> 2009-07-21 12:33:26,204 DEBUG org.apache.hadoop.hbase.regionserver.CompactSplitT
> hread: Compaction requested for region TestTable,0001724032,1248204794507/331335
> 5 because: Region has references on open
> 2009-07-21 12:33:26,204 INFO org.apache.hadoop.hbase.regionserver.HRegionServer:
> Worker: MSG_REGION_OPEN: TestTable,0001724032,1248204794507
> 2009-07-21 12:33:28,278 INFO org.apache.hadoop.hbase.regionserver.HRegionServer:
> MSG_REGION_CLOSE_WITHOUT_REPORT: TestTable,0001724032,1248204794507: Duplicate
> assignment
> 2009-07-21 12:33:28,279 INFO org.apache.hadoop.hbase.regionserver.HRegionServer:
> Worker: MSG_REGION_CLOSE_WITHOUT_REPORT: TestTable,0001724032,1248204794507: Du
> plicate assignment
> 2009-07-21 12:33:28,279 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Clos
> ing TestTable,0001724032,1248204794507: compactions & flushes disabled
> 2009-07-21 12:33:28,279 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Upda
> tes disabled for region, no outstanding scanners on TestTable,0001724032,1248204
> 794507
> 2009-07-21 12:33:28,279 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: No m
> ore row locks outstanding on region TestTable,0001724032,1248204794507
> 2009-07-21 12:33:28,279 INFO org.apache.hadoop.hbase.regionserver.HRegion: Close
> d TestTable,0001724032,1248204794507
> 2009-07-21 12:34:45,728 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Skip
> ping compaction on TestTable,0001724032,1248204794507 because closing/closed
> org.apache.hadoop.hbase.NotServingRegionException: TestTable,0001724032,12482047
> 94507
> 2009-07-21 13:24:35,902 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handl
> er 27 on 60020, call openScanner([B@1756ef1, startRow=0001700000, stopRow=, maxV
> ersions=1, timeRange=[0,9223372036854775807), families={(family=info, columns={d
> ata}}) from 10.10.30.105:50797: error: org.apache.hadoop.hbase.NotServingRegionE
> xception: TestTable,0001724032,1248204794507
> org.apache.hadoop.hbase.NotServingRegionException: TestTable,0001724032,12482047
> 94507
> org.apache.hadoop.hbase.NotServingRegionException: TestTable,0001724032,12482047
> 94507
> 2009-07-21 13:24:37,908 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handl
> er 19 on 60020, call openScanner([B@25b414, startRow=0001700000, stopRow=, maxVe
> rsions=1, timeRange=[0,9223372036854775807), families={(family=info, columns={da
> ta}}) from 10.10.30.105:50797: error: org.apache.hadoop.hbase.NotServingRegionEx
> ception: TestTable,0001724032,1248204794507
> org.apache.hadoop.hbase.NotServingRegionException: TestTable,0001724032,12482047
> 94507
> org.apache.hadoop.hbase.NotServingRegionException: TestTable,0001724032,12482047
> 94507
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.