You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Jimmy Xiang (JIRA)" <ji...@apache.org> on 2013/10/22 01:59:43 UTC
[jira] [Updated] (HBASE-9813) Log splitting doesn't prevent RS
creating new hlog file
[ https://issues.apache.org/jira/browse/HBASE-9813?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jimmy Xiang updated HBASE-9813:
-------------------------------
Status: Patch Available (was: Open)
> Log splitting doesn't prevent RS creating new hlog file
> -------------------------------------------------------
>
> Key: HBASE-9813
> URL: https://issues.apache.org/jira/browse/HBASE-9813
> Project: HBase
> Issue Type: Bug
> Reporter: Jimmy Xiang
> Assignee: Jimmy Xiang
> Attachments: trunk-9813.patch
>
>
> Here is something weird happened to my cluster. When the master recovered, it thought RS was dead by mistake and SSH processed it. Four hlog files were split and 4 regions were reassigned.
> Later on when the RS tried to report status, it got YouAreDeadException from master. Master tried to recover it again. Now SSH split one more hlog file, assigned 0 more extra region.
> Now the question is how come is the extra log file? I think it caused a data loss (one row) in my case. How can we prevent it? I can add a checking in the master to make sure a RS is really dead before marking it dead during recovery since it may be slow in reporting to the new master. But this is not a proper fix. A proper fix should be in the RS side, not creating the extra hlog file. Is this doable?
> Here is the related master log. The RS log does not have much thing interested.
> {noformat}
> 2013-10-20 17:40:33,025 INFO [master:e1119:36000] master.MasterFileSystem: Log folder hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312 doesn't belong to a known region server, splitting
> 2013-10-20 17:40:33,432 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] handler.ServerShutdownHandler: Splitting logs for e1521.halxg.cloudera.com,36020,1382314725312 before assignment.
> 2013-10-20 17:40:33,461 DEBUG [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.MasterFileSystem: Renamed region directory: hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting
> 2013-10-20 17:40:33,462 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.SplitLogManager: dead splitlog workers [e1521.halxg.cloudera.com,36020,1382314725312]
> 2013-10-20 17:40:33,467 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.SplitLogManager: started splitting 3 logs in [hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting]
> 2013-10-20 17:40:36,157 DEBUG [main-EventThread] wal.HLogSplitter: Archived processed log hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382315954499 to hdfs://e1119.halxg.cloudera.com:35802/hbase/oldWALs/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382315954499
> 2013-10-20 17:40:37,357 DEBUG [main-EventThread] wal.HLogSplitter: Archived processed log hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382315934942 to hdfs://e1119.halxg.cloudera.com:35802/hbase/oldWALs/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382315934942
> 2013-10-20 17:40:38,889 DEBUG [main-EventThread] wal.HLogSplitter: Archived processed log hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382315971393 to hdfs://e1119.halxg.cloudera.com:35802/hbase/oldWALs/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382315971393
> 2013-10-20 17:40:38,906 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.SplitLogManager: finished splitting (more than or equal to) 255322969 bytes in 3 log files in [hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting] in 5439ms
> 2013-10-20 17:40:38,907 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] handler.ServerShutdownHandler: Reassigning 4 region(s) that e1521.halxg.cloudera.com,36020,1382314725312 was carrying (and 0 regions(s) that were opening on this server)
> 2013-10-20 17:40:39,269 DEBUG [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.DeadServer: Finished processing e1521.halxg.cloudera.com,36020,1382314725312
> 2013-10-20 17:40:39,269 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] handler.ServerShutdownHandler: Finished processing of shutdown of e1521.halxg.cloudera.com,36020,1382314725312
> 2013-10-20 17:40:46,764 DEBUG [FifoRpcScheduler.handler1-thread-11] master.ServerManager: Server REPORT rejected; currently processing e1521.halxg.cloudera.com,36020,1382314725312 as dead server
> 2013-10-20 17:40:46,871 ERROR [FifoRpcScheduler.handler1-thread-13] master.HMaster: Region server e1521.halxg.cloudera.com,36020,1382314725312 reported a fatal error:
> ABORTING region server e1521.halxg.cloudera.com,36020,1382314725312: org.apache.hadoop.hbase.YouAreDeadException: Server REPORT rejected; currently processing e1521.halxg.cloudera.com,36020,1382314725312 as dead server
> org.apache.hadoop.hbase.YouAreDeadException: org.apache.hadoop.hbase.YouAreDeadException: Server REPORT rejected; currently processing e1521.halxg.cloudera.com,36020,1382314725312 as dead server
> Caused by: org.apache.hadoop.hbase.ipc.RemoteWithExtrasException(org.apache.hadoop.hbase.YouAreDeadException): org.apache.hadoop.hbase.YouAreDeadException: Server REPORT rejected; currently processing e1521.halxg.cloudera.com,36020,1382314725312 as dead server
> 2013-10-20 17:40:46,872 ERROR [FifoRpcScheduler.handler1-thread-14] master.HMaster: Region server e1521.halxg.cloudera.com,36020,1382314725312 reported a fatal error:
> ABORTING region server e1521.halxg.cloudera.com,36020,1382314725312: IOE in log roller
> java.io.FileNotFoundException: File does not exist: hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382315971393
> 2013-10-20 17:40:48,075 ERROR [FifoRpcScheduler.handler1-thread-15] master.HMaster: Region server e1521.halxg.cloudera.com,36020,1382314725312 reported a fatal error:
> ABORTING region server e1521.halxg.cloudera.com,36020,1382314725312: regionserver:36020-0x1419fea35edda89 regionserver:36020-0x1419fea35edda89 received expired from ZooKeeper, aborting
> 2013-10-20 17:53:15,272 INFO [master:e1119:36000] master.MasterFileSystem: Log folder hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312 doesn't belong to a known region server, splitting
> 2013-10-20 17:53:15,806 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] handler.ServerShutdownHandler: Splitting logs for e1521.halxg.cloudera.com,36020,1382314725312 before assignment.
> 2013-10-20 17:53:15,825 DEBUG [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.MasterFileSystem: Renamed region directory: hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting
> 2013-10-20 17:53:15,825 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.SplitLogManager: dead splitlog workers [e1521.halxg.cloudera.com,36020,1382314725312]
> 2013-10-20 17:53:15,831 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.SplitLogManager: started splitting 1 logs in [hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting]
> 2013-10-20 17:53:15,998 DEBUG [main-EventThread] wal.HLogSplitter: Archived processed log hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382316046805 to hdfs://e1119.halxg.cloudera.com:35802/hbase/oldWALs/e1521.halxg.cloudera.com%2C36020%2C1382314725312.1382316046805
> 2013-10-20 17:53:16,014 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] master.SplitLogManager: finished splitting (more than or equal to) 15 bytes in 1 log files in [hdfs://e1119.halxg.cloudera.com:35802/hbase/WALs/e1521.halxg.cloudera.com,36020,1382314725312-splitting] in 183ms
> 2013-10-20 17:53:16,015 INFO [MASTER_SERVER_OPERATIONS-e1119:36000-0] handler.ServerShutdownHandler: Reassigning 0 region(s) that e1521.halxg.cloudera.com,36020,1382314725312 was carrying (and 0 regions(s) that were opening on this server)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.1#6144)