Return-Path: X-Original-To: apmail-hbase-user-archive@www.apache.org Delivered-To: apmail-hbase-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 9014419DB2 for ; Mon, 11 Apr 2016 12:46:30 +0000 (UTC) Received: (qmail 35188 invoked by uid 500); 11 Apr 2016 12:46:28 -0000 Delivered-To: apmail-hbase-user-archive@hbase.apache.org Received: (qmail 35115 invoked by uid 500); 11 Apr 2016 12:46:28 -0000 Mailing-List: contact user-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@hbase.apache.org Delivered-To: mailing list user@hbase.apache.org Received: (qmail 35102 invoked by uid 99); 11 Apr 2016 12:46:28 -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; Mon, 11 Apr 2016 12:46:28 +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 E03FEC133B for ; Mon, 11 Apr 2016 12:46:27 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -0.802 X-Spam-Level: X-Spam-Status: No, score=-0.802 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, RCVD_IN_DNSWL_LOW=-0.7, RCVD_IN_MSPIKE_H2=-0.001, SPF_PASS=-0.001] autolearn=disabled Authentication-Results: spamd1-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com 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 xCFCFD-ramfh for ; Mon, 11 Apr 2016 12:46:25 +0000 (UTC) Received: from mail-pf0-f174.google.com (mail-pf0-f174.google.com [209.85.192.174]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTPS id E0F275F232 for ; Mon, 11 Apr 2016 12:46:24 +0000 (UTC) Received: by mail-pf0-f174.google.com with SMTP id c20so123518763pfc.1 for ; Mon, 11 Apr 2016 05:46:24 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=from:content-transfer-encoding:mime-version:subject:message-id:date :references:in-reply-to:to; bh=VXMA1EO9br9NlKCoOfnxPBJFo4NthgVyCo3Gm6MHHsc=; b=FCgONS3LVOE5oZGKsn9IUjevyLrp3SoT1xjRgIaGSuhOC67+NvsHWd/pcZpPZwZI1D U8CoCzOW859/ZxY7wbp/udsr76lqHM9HjU5fr0QJH3ZV82mdlKaAVP9DwlJxQ+vKt15h IjYaPdAgGVjlC16wcqJc7GCxKUTYn87dHuARuAza97fRyBpo05bLDKha1BSQH8oIGBYA m+M9o6Dw1hBKHcycvSPPB3Kb98aFoXbUnTQs8PT+cuXaDaxfdfO38TdbyNIoUuqa8Rx7 Mho5gpMJLbntrBLcJdj/y2XiKYxoB2xJRQQQoKcsjYdcO1WBmkKSFl4sKttwbrGD33KS wNkg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:from:content-transfer-encoding:mime-version :subject:message-id:date:references:in-reply-to:to; bh=VXMA1EO9br9NlKCoOfnxPBJFo4NthgVyCo3Gm6MHHsc=; b=V8PM6DLdZDiNi1PsX5QZ5lczvMYZSEtOIvVQa7m/hb9fM5XBqZ7ARPtbBfVsruOapn YgQ2vgQFRhEADQqH5PuD3ih0C9GaAcLTv5eJlRfksEy3xriFTlcPAL7LEUEnEiVPavnl c+60QdqU+gkOilz10W7AT8qTQM03uPTvwhvOpUCYdHnFbIViWcrv9lDGXyQZ0Uu8AiHh Fn3PN7i+zC8lF1Jpy+4jaRYh6f3GU8GivElX215H5o6TXnvFfCj45RAdg6Y34GSfSxi7 Zz17kbVE4fGgdR1BMJ4SZle+RWE84qVa79QAdDnEmAHBR32qKXDREdXYuFE6lLHzHQjF RtJA== X-Gm-Message-State: AD7BkJJ5kF0xR3KipdgP5blKNrk7Y/8SEo/uMjdJXcylrGzOETDaoZcIOt2A4BKKFU0oKg== X-Received: by 10.98.72.149 with SMTP id q21mr32594710pfi.148.1460378777877; Mon, 11 Apr 2016 05:46:17 -0700 (PDT) Received: from [192.168.0.11] (c-73-189-185-206.hsd1.ca.comcast.net. [73.189.185.206]) by smtp.gmail.com with ESMTPSA id z68sm36159180pfi.19.2016.04.11.05.46.16 for (version=TLSv1/SSLv3 cipher=OTHER); Mon, 11 Apr 2016 05:46:16 -0700 (PDT) From: Ted Yu Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: quoted-printable Mime-Version: 1.0 (1.0) Subject: Re: HBase 1.2 master CPU usage spin Message-Id: <100ECEDE-BD1C-461B-9E0B-82F91E502C95@gmail.com> Date: Mon, 11 Apr 2016 05:46:15 -0700 References: In-Reply-To: To: user@hbase.apache.org X-Mailer: iPhone Mail (13A344) Can you look at master log during this period to see what procedure was retr= ied ? Turning on DEBUG logging if necessary and pastebin relevant portion of maste= r log.=20 Thanks > On Apr 11, 2016, at 1:11 AM, Kevin Bowling wrot= e: >=20 > Hi, >=20 > I'm running HBase 1.2.0 on FreeBSD via the ports system ( > http://www.freshports.org/databases/hbase/), and it is generally working > well. However, in an HA setup, the HBase master spins at 200% CPU usage > when it is active and this follows the active master and disappears when > standby. Since this cluster is fairly idle, and an older production Linux= > one uses much less master CPU, I am curious what is going on. >=20 > Using visualvm, I can see that the ProcedureExecutor threads are quite > busy. Using dtrace, I can see that there is tons of native umtx activity.= > I am guessing that some procedure is failing, and continuously retrying as= > fast as the procedure dispatch allows. Using dtrace, I can also see that a= > lot of time seems to be spent in the JVM's 'libzip.so' native library. I'= m > wondering if it's a classloader run amok or something. >=20 > I need to rebuild the JVM with debugging to get more out of dtrace, but th= e > JVM doesn't implement a dtrace ustack helper for FreeBSD like it does on > Solarish. Hopefully then I can get some idea of what is going on. >=20 > Does this speak to anyone for ideas to look into? Other than noticing the= > CPU usage in top, the master seems to function fine and is responsive. >=20 > Here's a sample thread dump, this doesn't really jump out to me, but I > don't know if any of my captures are at the right moment either: >=20 > "ProcedureExecutor-7" - Thread t@116 > java.lang.Thread.State: WAITING > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <4653d04c> (a > java.util.concurrent.locks.ReentrantLock$NonfairSync) > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrup= t(AbstractQueuedSynchronizer.java:836) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Abstra= ctQueuedSynchronizer.java:870) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueu= edSynchronizer.java:1199) > at > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.ja= va:209) > at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285= ) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:145) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:139) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExe= cutor.java:803) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureE= xecutor.java:75) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecut= or.java:494) >=20 > Locked ownable synchronizers: > - None >=20 > "ProcedureExecutor-5" - Thread t@114 > java.lang.Thread.State: WAITING > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <4653d04c> (a > java.util.concurrent.locks.ReentrantLock$NonfairSync) > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrup= t(AbstractQueuedSynchronizer.java:836) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Abstra= ctQueuedSynchronizer.java:870) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueu= edSynchronizer.java:1199) > at > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.ja= va:209) > at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285= ) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:145) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:139) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExe= cutor.java:803) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureE= xecutor.java:75) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecut= or.java:494) >=20 > Locked ownable synchronizers: > - None >=20 > "ProcedureExecutor-4" - Thread t@113 > java.lang.Thread.State: WAITING > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <4653d04c> (a > java.util.concurrent.locks.ReentrantLock$NonfairSync) > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrup= t(AbstractQueuedSynchronizer.java:836) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Abstra= ctQueuedSynchronizer.java:870) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueu= edSynchronizer.java:1199) > at > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.ja= va:209) > at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285= ) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:145) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:139) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExe= cutor.java:803) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureE= xecutor.java:75) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecut= or.java:494) >=20 > Locked ownable synchronizers: > - None >=20 > "ProcedureExecutor-3" - Thread t@112 > java.lang.Thread.State: WAITING > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <4653d04c> (a > java.util.concurrent.locks.ReentrantLock$NonfairSync) > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrup= t(AbstractQueuedSynchronizer.java:836) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Abstra= ctQueuedSynchronizer.java:870) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueu= edSynchronizer.java:1199) > at > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.ja= va:209) > at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285= ) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:145) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:139) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExe= cutor.java:803) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureE= xecutor.java:75) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecut= or.java:494) >=20 > Locked ownable synchronizers: > - None >=20 > "ProcedureExecutor-2" - Thread t@111 > java.lang.Thread.State: WAITING > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <4653d04c> (a > java.util.concurrent.locks.ReentrantLock$NonfairSync) > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrup= t(AbstractQueuedSynchronizer.java:836) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Abstra= ctQueuedSynchronizer.java:870) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueu= edSynchronizer.java:1199) > at > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.ja= va:209) > at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285= ) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:145) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:139) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExe= cutor.java:803) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureE= xecutor.java:75) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecut= or.java:494) >=20 > Locked ownable synchronizers: > - None >=20 > "ProcedureExecutor-1" - Thread t@110 > java.lang.Thread.State: RUNNABLE > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:139) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExe= cutor.java:803) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureE= xecutor.java:75) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecut= or.java:494) >=20 > Locked ownable synchronizers: > - None >=20 > "ProcedureExecutor-0" - Thread t@109 > java.lang.Thread.State: WAITING > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <4653d04c> (a > java.util.concurrent.locks.ReentrantLock$NonfairSync) > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrup= t(AbstractQueuedSynchronizer.java:836) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Abstra= ctQueuedSynchronizer.java:870) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueu= edSynchronizer.java:1199) > at > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.ja= va:209) > at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285= ) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:145) > at > org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler.poll(Mas= terProcedureScheduler.java:139) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execLoop(ProcedureExe= cutor.java:803) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$400(ProcedureE= xecutor.java:75) > at > org.apache.hadoop.hbase.procedure2.ProcedureExecutor$2.run(ProcedureExecut= or.java:494) >=20 > Locked ownable synchronizers: > - None