hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "stack (JIRA)" <j...@apache.org>
Subject [jira] Resolved: (HBASE-1750) Region opens and assignment running independent of shutdown processing
Date Thu, 03 Jun 2010 17:37:01 GMT

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

stack resolved HBASE-1750.
--------------------------

    Resolution: Cannot Reproduce

This does not seem possible anymore as per j-d comment above and I've not seen it in ages...
resolving.

> Region opens and assignment running independent of shutdown processing
> ----------------------------------------------------------------------
>
>                 Key: HBASE-1750
>                 URL: https://issues.apache.org/jira/browse/HBASE-1750
>             Project: HBase
>          Issue Type: Bug
>    Affects Versions: 0.20.0
>            Reporter: stack
>            Priority: Blocker
>             Fix For: 0.21.0
>
>
> This is so broke, its hard to know where to start.
> In the below, node 14 expires, we continue to take on messages from it queueing open
region todos for us to work on later.  Then we start to process shutdown of server 14.  Meantime
we are assigning it regions.
> Later, not reported here.  The open of a particular region is queued on the todo list
> 1 time.  Processing the 2nd and 3rd times we call the assignment a duplicate and tell
remote server close its region (it'll be same region as was in the first todo message).  It
dutifully closes without report.  Now we NSRE till the end of time trying to find this closed
region.
> {code}
> 2009-08-05 04:39:12,007 [main-SendThread] DEBUG org.apache.zookeeper.ClientCnxn: Got
notification sessionid:0x22e734176a0001
> 2009-08-05 04:39:12,007 [main-SendThread] DEBUG org.apache.zookeeper.ClientCnxn: Got
WatchedEvent: Znode change. Path: /hbase/rs/1249419499242 Type: NodeDeleted for sessionid
0x22e734176a0001
> 2009-08-05 04:39:12,007 [main-EventThread] INFO org.apache.hadoop.hbase.master.ServerManager:
14.powerset.com,60020,1249419499242 znode expired
> 2009-08-05 04:39:12,137 [IPC Server handler 22 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.142:60020, startcode: 1249419499272, load: (requests=5, regions=243,
 
> usedHeap=732, maxHeap=1391): total nregions to assign=7, nregions to reach balance=7,
isMetaAssign=false
> 2009-08-05 04:39:13,028 [main-SendThread] DEBUG org.apache.zookeeper.ClientCnxn: Got
ping response for sessionid:0x22e734176a0001 after 0ms
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0707104931,1249439925123 from 14.powerset.com,60
> 020,1249447142944; 1 of 19
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0807477918,1249435417405 from 14.powerset.com,60
> 020,1249447142944; 2 of 19
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0239771780,1249436471662 from 14.powerset.com,60
> 020,1249447142944; 3 of 19
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0295087929,1249438529628 from 14.powerset.com,60
> 020,1249447142944; 4 of 19
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0344538034,1249438625837 from 14.powerset.com,60
> 020,1249447142944; 5 of 19
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0067977092,1249431465797 from 14.powerset.com,60
> 020,1249447142944; 6 of 19
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0521945645,1249426826597 from 14.powerset.com,60
> 020,1249447142944; 7 of 19
> 2009-08-05 04:39:13,554 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0221136504,1249447128488 from 14.powerset.com,60
> 020,1249447142944; 8 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_PROCESS_OPEN: TestTable,0272411446,1249433459428 from 14.powerset.com,60
> 020,1249447142944; 9 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0284541889,1249434580130 from 14.powerset.com,60020,1249
> 447142944; 10 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0707104931,1249439925123 from 14.powerset.com,60020,1249
> 447142944; 11 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0807477918,1249435417405 from 14.powerset.com,60020,1249
> 447142944; 12 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0239771780,1249436471662 from 14.powerset.com,60020,1249
> 447142944; 13 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0295087929,1249438529628 from 14.powerset.com,60020,1249
> 447142944; 14 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0344538034,1249438625837 from 14.powerset.com,60020,1249
> 447142944; 15 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0067977092,1249431465797 from 14.powerset.com,60020,1249
> 447142944; 16 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0521945645,1249426826597 from 14.powerset.com,60020,1249
> 447142944; 17 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0221136504,1249447128488 from 14.powerset.com,60020,1249
> 447142944; 18 of 19
> 2009-08-05 04:39:13,555 [IPC Server handler 4 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager:
Processing MSG_REPORT_OPEN: TestTable,0272411446,1249433459428 from 14.powerset.com,60020,1249
> 447142944; 19 of 19
> 2009-08-05 04:39:14,260 [IPC Server handler 24 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.140:60020, startcode: 1249419499240, load: (requests=0, regions=236,
 
> usedHeap=644, maxHeap=1391): total nregions to assign=7, nregions to reach balance=7,
isMetaAssign=false
> 2009-08-05 04:39:14,994 [IPC Server handler 3 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.139:60020, startcode: 1249419499241, load: (requests=0, regions=242,
u
> sedHeap=715, maxHeap=1391): total nregions to assign=7, nregions to reach balance=7,
isMetaAssign=false
> 2009-08-05 04:39:15,196 [IPC Server handler 2 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.142:60020, startcode: 1249419499272, load: (requests=0, regions=243,
u
> sedHeap=733, maxHeap=1391): total nregions to assign=7, nregions to reach balance=7,
isMetaAssign=false
> 2009-08-05 04:39:15,289 [HMaster-SendThread] DEBUG org.apache.zookeeper.ClientCnxn: Got
ping response for sessionid:0x22e734176a0002 after 1ms
> 2009-08-05 04:39:15,319 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,321 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,321 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,322 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,323 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,325 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:14,260 [IPC Server handler 24 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.140:60020, startcode: 1249419499240, load: (requests=0, regions=236,

> usedHeap=644, maxHeap=1391): total nregions to assign=7, nregions to reach balance=7,
isMetaAssign=false
> 2009-08-05 04:39:14,994 [IPC Server handler 3 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.139:60020, startcode: 1249419499241, load: (requests=0, regions=242,
u
> sedHeap=715, maxHeap=1391): total nregions to assign=7, nregions to reach balance=7,
isMetaAssign=false
> 2009-08-05 04:39:15,196 [IPC Server handler 2 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.142:60020, startcode: 1249419499272, load: (requests=0, regions=243,
u
> sedHeap=733, maxHeap=1391): total nregions to assign=7, nregions to reach balance=7,
isMetaAssign=false
> 2009-08-05 04:39:15,289 [HMaster-SendThread] DEBUG org.apache.zookeeper.ClientCnxn: Got
ping response for sessionid:0x22e734176a0002 after 1ms
> 2009-08-05 04:39:15,319 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,321 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,321 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,322 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,323 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,325 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,327 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,328 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,330 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: RegionAssignmentHistorian from 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:15,331 [HMaster] DEBUG org.apache.hadoop.hbase.master.HMaster: Processing
todo: ProcessServerShutdown of 14.powerset.com,60020,1249419499242
> 2009-08-05 04:39:15,331 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation:
process shutdown of server 14.powerset.com,60020,1249419499242: logSplit: false, rootRescanned:
false, numbe
> rOfMetaRegions: 1, onlineMetaRegions.size(): 1
> 2009-08-05 04:39:15,340 [HMaster] INFO org.apache.hadoop.hbase.regionserver.HLog: Splitting
34 hlog(s) in hdfs://12.powerset.com:9002/hbase/.logs/14.powerset.com,60020,1249419499242
> 2009-08-05 04:39:15,341 [HMaster] DEBUG org.apache.hadoop.hbase.regionserver.HLog: Splitting
hlog 1 of 34: hdfs://12.powerset.com:9002/hbase/.logs/14.powerset.com,60020,1249419499242/hlog.dat
> .1249446428006, length=58628658
> 2009-08-05 04:39:15,412 [HMaster] DEBUG org.apache.hadoop.hbase.regionserver.HLog: Adding
queue for TestTable,0855568194,1249436793311
> 2009-08-05 04:39:15,989 [HMaster] DEBUG org.apache.hadoop.hbase.regionserver.HLog: Adding
queue for TestTable,0839835862,1249431318932
> 2009-08-05 04:39:16,030 [HMaster] DEBUG org.apache.hadoop.hbase.regionserver.HLog: Adding
queue for TestTable,0470769394,1249439783171
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Assigning for address: XX.XX.XX.141:60020, startcode: 1249447142944, load: (requests=0, regions=10,
us
> edHeap=51, maxHeap=1391): total nregions to assign=7, nregions to reach balance=0, isMetaAssign=false
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] DEBUG org.apache.hadoop.hbase.master.RegionManager:
Doing for address: XX.XX.XX.141:60020, startcode: 1249447142944, load: (requests=0, regions=10,
usedHe
> ap=51, maxHeap=1391) nregions: 7 and nRegionsToAssign: 7
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region TestTable,0196260871,1249434878197 to 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region TestTable,0831634449,1249445668584 to 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region TestTable,0621687088,1249440865643 to 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region TestTable,0046898120,1249435993439 to 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region TestTable,0706868362,1249439909374 to 14.powerset.com,60020,1249447142944
> 2009-08-05 04:39:16,566 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager:
Assigning region TestTable,0226534644,1249438950155 to 14.powerset.com,60020,1249447142944
> {code}

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


Mime
View raw message