Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id E2B18200D71 for ; Thu, 21 Dec 2017 03:56:06 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id E1361160C18; Thu, 21 Dec 2017 02:56:06 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 0DB18160C15 for ; Thu, 21 Dec 2017 03:56:05 +0100 (CET) Received: (qmail 21858 invoked by uid 500); 21 Dec 2017 02:56:04 -0000 Mailing-List: contact issues-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Delivered-To: mailing list issues@hbase.apache.org Received: (qmail 21845 invoked by uid 99); 21 Dec 2017 02:56:04 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd1-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 21 Dec 2017 02:56:04 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd1-us-west.apache.org (ASF Mail Server at spamd1-us-west.apache.org) with ESMTP id 6E2B9C4F16 for ; Thu, 21 Dec 2017 02:56:04 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -99.211 X-Spam-Level: X-Spam-Status: No, score=-99.211 tagged_above=-999 required=6.31 tests=[KAM_ASCII_DIVIDERS=0.8, RCVD_IN_DNSWL_NONE=-0.0001, SPF_PASS=-0.001, T_RP_MATCHES_RCVD=-0.01, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id KRokO78wZbie for ; Thu, 21 Dec 2017 02:56:03 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id 70EA25F254 for ; Thu, 21 Dec 2017 02:56:02 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id 9E313E0DE3 for ; Thu, 21 Dec 2017 02:56:01 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 52ED6240DE for ; Thu, 21 Dec 2017 02:56:00 +0000 (UTC) Date: Thu, 21 Dec 2017 02:56:00 +0000 (UTC) From: "Yi Liang (JIRA)" To: issues@hbase.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (HBASE-19218) Master stuck thinking hbase:namespace is assigned after restart preventing intialization MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 21 Dec 2017 02:56:07 -0000 [ https://issues.apache.org/jira/browse/HBASE-19218?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16299460#comment-16299460 ] Yi Liang commented on HBASE-19218: ---------------------------------- patch is good. +1 > Master stuck thinking hbase:namespace is assigned after restart preventing intialization > ---------------------------------------------------------------------------------------- > > Key: HBASE-19218 > URL: https://issues.apache.org/jira/browse/HBASE-19218 > Project: HBase > Issue Type: Bug > Reporter: Josh Elser > Assignee: stack > Priority: Critical > Fix For: 2.0.0-beta-1 > > Attachments: HBASE-19218.master.001.patch, hbase-hbase-master-ctr-e134-1499953498516-282290-01-000003.hwx.site.log.zip, hbase-site.xml > > > Our [~romil.choksi] brought this one to my attention after trying to get some cluster tests running. > The Master seems to have gotten stuck never initializing after it thinks that hbase:namespace was already deployed on the cluster when it actually was not. On a Master restart, it reads the location out of meta and assumes that it's there (I assume this invalid entry is the issue): > {noformat} > 2017-11-08 00:29:17,556 INFO [ctr-e134-1499953498516-282290-01-000003:20000.masterManager] assignment.RegionStateStore: Load hbase:meta entry region={ENCODED => f147f204a579b885c351bdc0a7ebbf94, NAME => 'hbase:namespace,,1510084256045.f147f204a579b885c351bdc0a7ebbf94.', STARTKEY => '', ENDKEY => ''} regionState=OPENING lastHost=ctr-e134-1499953498516-282290-01-000005.hwx.site,16020,1510084579728 regionLocation=ctr-e134-1499953498516-282290-01-000005.hwx.site,16020,1510100695534 > {noformat} > Prior to this, the RS5 went through the ServerCrashProcedure, but it looks like this bailed out unexpectedly: > {noformat} > 2017-11-08 00:25:25,187 WARN [ctr-e134-1499953498516-282290-01-000003:20000.masterManager] master.ServerManager: Expiration of ctr-e134-1499953498516-282290-01-000005.hwx.site,16020,1510084579728 but server not online > 2017-11-08 00:25:25,187 INFO [ProcExecWrkr-5] procedure.ServerCrashProcedure: Start pid=36, state=RUNNABLE:SERVER_CRASH_START; ServerCrashProcedure server=ctr-e134-1499953498516-282290-01-000003.hwx.site,16020,1510084580111, splitWal=t > rue, meta=false > 2017-11-08 00:25:25,188 INFO [ctr-e134-1499953498516-282290-01-000003:20000.masterManager] master.ServerManager: Processing expiration of ctr-e134-1499953498516-282290-01-000005.hwx.site,16020,1510084579728 on ctr-e134-1499953498516-28 > 2290-01-000003.hwx.site,20000,1510100690324 > ... > 2017-11-08 00:25:27,211 ERROR [ProcExecWrkr-22] procedure2.ProcedureExecutor: CODE-BUG: Uncaught runtime exception: pid=40, ppid=37, state=RUNNABLE:REGION_TRANSITION_QUEUE; AssignProcedure table=hbase:namespace, region=f147f204a579b885c351bdc0a7ebbf94 > java.lang.NullPointerException > at java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) > at org.apache.hadoop.hbase.procedure2.RemoteProcedureDispatcher.addOperationToNode(RemoteProcedureDispatcher.java:171) > at org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.addToRemoteDispatcher(RegionTransitionProcedure.java:223) > at org.apache.hadoop.hbase.master.assignment.AssignProcedure.updateTransition(AssignProcedure.java:252) > at org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.execute(RegionTransitionProcedure.java:309) > at org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.execute(RegionTransitionProcedure.java:82) > at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:845) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1452) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1221) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$800(ProcedureExecutor.java:77) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1731) > 2017-11-08 00:25:27,239 FATAL [ProcExecWrkr-22] procedure2.ProcedureExecutor: CODE-BUG: Uncaught runtime exception for pid=37, state=FAILED:SERVER_CRASH_FINISH, exception=java.lang.NullPointerException via CODE-BUG: Uncaught runtime exception: pid=40, ppid=37, state=RUNNABLE:REGION_TRANSITION_QUEUE; AssignProcedure table=hbase:namespace, region=f147f204a579b885c351bdc0a7ebbf94:java.lang.NullPointerException; ServerCrashProcedure server=ctr-e134-1499953498516-282290-01-000005.hwx.site,16020,1510084579728, splitWal=true, meta=false > java.lang.UnsupportedOperationException: unhandled state=SERVER_CRASH_FINISH > at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.rollbackState(ServerCrashProcedure.java:236) > at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.rollbackState(ServerCrashProcedure.java:56) > at org.apache.hadoop.hbase.procedure2.StateMachineProcedure.rollback(StateMachineProcedure.java:198) > at org.apache.hadoop.hbase.procedure2.Procedure.doRollback(Procedure.java:859) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeRollback(ProcedureExecutor.java:1353) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeRollback(ProcedureExecutor.java:1309) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1178) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$800(ProcedureExecutor.java:77) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1731) > 2017-11-08 00:25:27,344 FATAL [ProcExecWrkr-8] procedure2.ProcedureExecutor: CODE-BUG: Uncaught runtime exception for pid=37, state=FAILED:SERVER_CRASH_FINISH, exception=java.lang.NullPointerException via CODE-BUG: Uncaught runtime exception: pid=40, ppid=37, state=RUNNABLE:REGION_TRANSITION_QUEUE; AssignProcedure table=hbase:namespace, region=f147f204a579b885c351bdc0a7ebbf94:java.lang.NullPointerException; ServerCrashProcedure server=ctr-e134-1499953498516-282290-01-000005.hwx.site,16020,1510084579728, splitWal=true, meta=false > java.lang.UnsupportedOperationException: unhandled state=SERVER_CRASH_FINISH > at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.rollbackState(ServerCrashProcedure.java:236) > at org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure.rollbackState(ServerCrashProcedure.java:56) > at org.apache.hadoop.hbase.procedure2.StateMachineProcedure.rollback(StateMachineProcedure.java:198) > at org.apache.hadoop.hbase.procedure2.Procedure.doRollback(Procedure.java:859) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeRollback(ProcedureExecutor.java:1353) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeRollback(ProcedureExecutor.java:1309) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1178) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$800(ProcedureExecutor.java:77) > at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1731) > 2017-11-08 00:25:27,356 INFO [ProcExecWrkr-5] procedure2.ProcedureExecutor: Rolled back pid=37, state=ROLLEDBACK, exception=java.lang.NullPointerException via CODE-BUG: Uncaught runtime exception: pid=40, ppid=37, state=RUNNABLE:REGION_TRANSITION_QUEUE; AssignProcedure table=hbase:namespace, region=f147f204a579b885c351bdc0a7ebbf94:java.lang.NullPointerException; ServerCrashProcedure server=ctr-e134-1499953498516-282290-01-000005.hwx.site,16020,1510084579728, splitWal=true, meta=false exec-time=2.1650sec > {noformat} > Shortly after this, the master was restarted. > My hunch is that because the SCP crashed, we never invalidated the meta entries and got us stuck thinking the region was assigned when it wasn't? -- This message was sent by Atlassian JIRA (v6.4.14#64029)