Return-Path: X-Original-To: apmail-hbase-issues-archive@www.apache.org Delivered-To: apmail-hbase-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 73A2711F5F for ; Mon, 14 Apr 2014 23:11:34 +0000 (UTC) Received: (qmail 89379 invoked by uid 500); 14 Apr 2014 23:11:24 -0000 Delivered-To: apmail-hbase-issues-archive@hbase.apache.org Received: (qmail 89196 invoked by uid 500); 14 Apr 2014 23:11:21 -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 89176 invoked by uid 99); 14 Apr 2014 23:11:21 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 14 Apr 2014 23:11:21 +0000 Date: Mon, 14 Apr 2014 23:11:21 +0000 (UTC) From: "stack (JIRA)" To: issues@hbase.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (HBASE-10977) TestHBaseFsck.testQuarantineMissingHFile fails missing files test MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/HBASE-10977?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13968982#comment-13968982 ] stack commented on HBASE-10977: ------------------------------- This is not same as HBASE-9851 > TestHBaseFsck.testQuarantineMissingHFile fails missing files test > ----------------------------------------------------------------- > > Key: HBASE-10977 > URL: https://issues.apache.org/jira/browse/HBASE-10977 > Project: HBase > Issue Type: Bug > Reporter: stack > Priority: Minor > > On our internal rig, ran into this failure: > {code} > java.lang.AssertionError: expected:<2> but was:<1> > at org.junit.Assert.fail(Assert.java:88) > at org.junit.Assert.failNotEquals(Assert.java:743) > at org.junit.Assert.assertEquals(Assert.java:118) > at org.junit.Assert.assertEquals(Assert.java:555) > at org.junit.Assert.assertEquals(Assert.java:542) > at org.apache.hadoop.hbase.util.TestHBaseFsck.doQuarantineTest(TestHBaseFsck.java:1737) > at org.apache.hadoop.hbase.util.TestHBaseFsck.testQuarantineMissingHFile(TestHBaseFsck.java:1781) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) > at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) > at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > at org.junit.internal.runners.statements.FailOnTimeout$StatementThread.run(FailOnTimeout.java:74) > {code} > This is what is failing: > assertEquals(hfcc.getMissing().size(), missing); > The file remove has not run yet or, else, this complaint is related: > {code} > 2014-04-12 23:24:57,638 WARN [IPC Server handler 4 on 50919] security.UserGroupInformation(1551): PriviledgedActionException as:jenkins (auth:SIMPLE) cause:java.io.FileNotFoundException: File does not exist: /user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/fam/57a07eaac97e4acd8dc04e08d1950adc > {code} > Below is full log. Will come back and add logging.... > {code} > Regression > org.apache.hadoop.hbase.util.TestHBaseFsck.testQuarantineMissingHFile > Failing for the past 1 build (Since Failed#3 ) > Took 10 ms. > add description > Error Message > expected:<2> but was:<1> > Stacktrace > java.lang.AssertionError: expected:<2> but was:<1> > at org.junit.Assert.fail(Assert.java:88) > at org.junit.Assert.failNotEquals(Assert.java:743) > at org.junit.Assert.assertEquals(Assert.java:118) > at org.junit.Assert.assertEquals(Assert.java:555) > at org.junit.Assert.assertEquals(Assert.java:542) > at org.apache.hadoop.hbase.util.TestHBaseFsck.doQuarantineTest(TestHBaseFsck.java:1737) > at org.apache.hadoop.hbase.util.TestHBaseFsck.testQuarantineMissingHFile(TestHBaseFsck.java:1781) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) > at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) > at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > at org.junit.internal.runners.statements.FailOnTimeout$StatementThread.run(FailOnTimeout.java:74) > Standard Output > Allow checking/fixes for table: testQuarantineMissingHFile > Checked 4 hfile for corruption > HFiles corrupted: 0 > HFiles successfully quarantined: 0 > HFiles failed quarantine: 0 > HFiles moved while checking: 2 > hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/fam/57a07eaac97e4acd8dc04e08d1950adc > hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/fam/9dd79f30f29e4cfeaa46f6e20b32e078 > Summary: OK => OK > Version: 0.96.1.1-cdh5.0.1-SNAPSHOT > ---- Table 'testQuarantineMissingHFile': region split map > : [ { meta => null, hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e, deployed => }, A] > A: [ { meta => null, hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef, deployed => }, B] > B: [ { meta => null, hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351, deployed => }, C] > C: [ { meta => null, hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d, deployed => }, ] > null: > ---- Table 'testQuarantineMissingHFile': overlap groups > There are 0 overlap groups with 0 overlapping regions > ---- Table 'hbase:meta': region split map > : [ { meta => null, hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/hbase/meta/1588230740, deployed => }, ] > null: > ---- Table 'hbase:meta': overlap groups > There are 0 overlap groups with 0 overlapping regions > Number of live region servers: 3 > p0419.mtv.cloudera.com,41017,1397370264982 > p0419.mtv.cloudera.com,39010,1397370264935 > p0419.mtv.cloudera.com,32877,1397370265023 > Number of dead region servers: 0 > Master: p0419.mtv.cloudera.com,33001,1397370264247 > Number of backup masters: 0 > Average load: 2.0 > Number of requests: 655 > Number of regions: 6 > Number of regions in transition: 0 > RegionServer: p0419.mtv.cloudera.com,32877,1397370265023 number of regions: 0 > RegionServer: p0419.mtv.cloudera.com,39010,1397370264935 number of regions: 0 > RegionServer: p0419.mtv.cloudera.com,41017,1397370264982 number of regions: 1 > hbase:meta,,1.1588230740 id: 1 encoded_name: 1588230740 start: end: > Number of empty REGIONINFO_QUALIFIER rows in hbase:meta: 0 > Number of Tables: 0 > Number of Tables in flux: 1 > ---- Table 'hbase:meta': region split map > : [ { meta => hbase:meta,,1.1588230740, hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/hbase/meta/1588230740, deployed => p0419.mtv.cloudera.com,41017,1397370264982;hbase:meta,,1.1588230740 }, ] > null: > ---- Table 'hbase:meta': overlap groups > There are 0 overlap groups with 0 overlapping regions > Summary: > testQuarantineMissingHFile is okay. > Number of regions: 0 > Deployed on: > hbase:meta is okay. > Number of regions: 1 > Deployed on: p0419.mtv.cloudera.com,41017,1397370264982 > 0 inconsistencies detected. > Status: OK > Standard Error > 2014-04-12 23:24:54,802 INFO [pool-1-thread-1] hbase.ResourceChecker(147): before: util.TestHBaseFsck#testQuarantineMissingHFile Thread=410, OpenFileDescriptor=691, MaxFileDescriptor=32768, SystemLoadAverage=422, ProcessCount=485, AvailableMemoryMB=3139, ConnectionCount=5 > 2014-04-12 23:24:54,809 INFO [RpcServer.handler=0,port=33001] master.HMaster(1748): Client=jenkins//172.29.122.11 create 'testQuarantineMissingHFile', {NAME => 'fam', DATA_BLOCK_ENCODING => 'NONE', BLOOMFILTER => 'ROW', REPLICATION_SCOPE => '0', VERSIONS => '1', COMPRESSION => 'NONE', MIN_VERSIONS => '0', TTL => '2147483647', KEEP_DELETED_CELLS => 'false', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'} > 2014-04-12 23:24:54,886 DEBUG [RpcServer.handler=0,port=33001] lock.ZKInterProcessLockBase(226): Acquired a lock for /hbase/table-lock/testQuarantineMissingHFile/write-master:330010000000000 > 2014-04-12 23:24:54,960 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.CreateTableHandler(148): Create table testQuarantineMissingHFile > 2014-04-12 23:24:55,060 INFO [IPC Server handler 6 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741867_1043{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,061 INFO [IPC Server handler 3 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741867_1043{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,062 INFO [IPC Server handler 5 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741867_1043 size 305 > 2014-04-12 23:24:55,185 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] util.FSTableDescriptors(640): Wrote descriptor into: hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/.tabledesc/.tableinfo.0000000001 > 2014-04-12 23:24:55,188 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-1] regionserver.HRegion(3969): creating HRegion testQuarantineMissingHFile HTD == 'testQuarantineMissingHFile', {NAME => 'fam', DATA_BLOCK_ENCODING => 'NONE', BLOOMFILTER => 'ROW', REPLICATION_SCOPE => '0', VERSIONS => '1', COMPRESSION => 'NONE', MIN_VERSIONS => '0', TTL => '2147483647', KEEP_DELETED_CELLS => 'false', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'} RootDir = hdfs://localhost:50919/user/jenkins/hbase/.tmp Table name == testQuarantineMissingHFile > 2014-04-12 23:24:55,188 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-2] regionserver.HRegion(3969): creating HRegion testQuarantineMissingHFile HTD == 'testQuarantineMissingHFile', {NAME => 'fam', DATA_BLOCK_ENCODING => 'NONE', BLOOMFILTER => 'ROW', REPLICATION_SCOPE => '0', VERSIONS => '1', COMPRESSION => 'NONE', MIN_VERSIONS => '0', TTL => '2147483647', KEEP_DELETED_CELLS => 'false', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'} RootDir = hdfs://localhost:50919/user/jenkins/hbase/.tmp Table name == testQuarantineMissingHFile > 2014-04-12 23:24:55,188 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-3] regionserver.HRegion(3969): creating HRegion testQuarantineMissingHFile HTD == 'testQuarantineMissingHFile', {NAME => 'fam', DATA_BLOCK_ENCODING => 'NONE', BLOOMFILTER => 'ROW', REPLICATION_SCOPE => '0', VERSIONS => '1', COMPRESSION => 'NONE', MIN_VERSIONS => '0', TTL => '2147483647', KEEP_DELETED_CELLS => 'false', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'} RootDir = hdfs://localhost:50919/user/jenkins/hbase/.tmp Table name == testQuarantineMissingHFile > 2014-04-12 23:24:55,188 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-4] regionserver.HRegion(3969): creating HRegion testQuarantineMissingHFile HTD == 'testQuarantineMissingHFile', {NAME => 'fam', DATA_BLOCK_ENCODING => 'NONE', BLOOMFILTER => 'ROW', REPLICATION_SCOPE => '0', VERSIONS => '1', COMPRESSION => 'NONE', MIN_VERSIONS => '0', TTL => '2147483647', KEEP_DELETED_CELLS => 'false', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'} RootDir = hdfs://localhost:50919/user/jenkins/hbase/.tmp Table name == testQuarantineMissingHFile > 2014-04-12 23:24:55,378 INFO [IPC Server handler 2 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741869_1045{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,379 INFO [IPC Server handler 0 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741869_1045{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,379 INFO [IPC Server handler 1 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741869_1045{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,386 INFO [IPC Server handler 9 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741868_1044{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,387 INFO [IPC Server handler 2 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741868_1044{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,388 INFO [IPC Server handler 1 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741868_1044 size 61 > 2014-04-12 23:24:55,410 INFO [IPC Server handler 9 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741871_1047{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,410 INFO [IPC Server handler 2 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741871_1047{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,411 INFO [IPC Server handler 4 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741871_1047 size 61 > 2014-04-12 23:24:55,418 INFO [IPC Server handler 8 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741870_1046{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,418 INFO [IPC Server handler 9 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741870_1046{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:55,419 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-3] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:55,419 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-3] regionserver.HRegion(988): Closing testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.: disabling compactions & flushes > 2014-04-12 23:24:55,419 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-3] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:55,419 INFO [IPC Server handler 4 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741870_1046 size 60 > 2014-04-12 23:24:55,419 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-3] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:55,458 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-1] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:55,458 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-2] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:55,459 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-1] regionserver.HRegion(988): Closing testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.: disabling compactions & flushes > 2014-04-12 23:24:55,459 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-2] regionserver.HRegion(988): Closing testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.: disabling compactions & flushes > 2014-04-12 23:24:55,459 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-1] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:55,459 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-2] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:55,459 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-1] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:55,459 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-2] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:55,460 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-4] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:55,461 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-4] regionserver.HRegion(988): Closing testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.: disabling compactions & flushes > 2014-04-12 23:24:55,461 DEBUG [RegionOpenAndInitThread-testQuarantineMissingHFile-4] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:55,461 INFO [RegionOpenAndInitThread-testQuarantineMissingHFile-4] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:55,502 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] catalog.MetaEditor(278): Added 4 > 2014-04-12 23:24:55,503 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] master.AssignmentManager(2506): Bulk assigning 4 region(s) across 3 server(s), round-robin=true > 2014-04-12 23:24:55,503 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-0] master.AssignmentManager(1451): Assigning 1 region(s) to p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,503 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-1] master.AssignmentManager(1451): Assigning 1 region(s) to p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,503 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-2] master.AssignmentManager(1451): Assigning 2 region(s) to p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,504 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-1] zookeeper.ZKAssign(175): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Async create of unassigned node a8a68d998d21b00499aca60887ae5aef with OFFLINE state > 2014-04-12 23:24:55,504 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-2] zookeeper.ZKAssign(175): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Async create of unassigned node d383980be98665b638fd56bfac97a351 with OFFLINE state > 2014-04-12 23:24:55,503 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-0] zookeeper.ZKAssign(175): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Async create of unassigned node 63cdcba1fc55ae6463463ae16f4e454e with OFFLINE state > 2014-04-12 23:24:55,503 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] master.GeneralBulkAssigner(177): Timeout-on-RIT=152000 > 2014-04-12 23:24:55,504 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-2] zookeeper.ZKAssign(175): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Async create of unassigned node f9c185520bca999a753ee3ce0a244f6d with OFFLINE state > 2014-04-12 23:24:55,510 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/region-in-transition > 2014-04-12 23:24:55,510 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback(69): rs={a8a68d998d21b00499aca60887ae5aef state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,511 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback(69): rs={d383980be98665b638fd56bfac97a351 state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,518 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback(69): rs={63cdcba1fc55ae6463463ae16f4e454e state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,519 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback(69): rs={f9c185520bca999a753ee3ce0a244f6d state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,519 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback$ExistCallback(106): rs={a8a68d998d21b00499aca60887ae5aef state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,519 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback$ExistCallback(106): rs={d383980be98665b638fd56bfac97a351 state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,519 INFO [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-1] master.AssignmentManager(1502): p0419.mtv.cloudera.com,39010,1397370264935 unassigned znodes=1 of total=1 > 2014-04-12 23:24:55,519 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback$ExistCallback(106): rs={63cdcba1fc55ae6463463ae16f4e454e state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,519 INFO [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-1] master.RegionStates(316): Transitioned {a8a68d998d21b00499aca60887ae5aef state=OFFLINE, ts=1397370295504, server=null} to {a8a68d998d21b00499aca60887ae5aef state=PENDING_OPEN, ts=1397370295519, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:55,519 DEBUG [pool-1-thread-1-EventThread] master.OfflineCallback$ExistCallback(106): rs={f9c185520bca999a753ee3ce0a244f6d state=OFFLINE, ts=1397370295502, server=null}, server=p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,519 INFO [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-0] master.AssignmentManager(1502): p0419.mtv.cloudera.com,32877,1397370265023 unassigned znodes=1 of total=1 > 2014-04-12 23:24:55,520 INFO [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-2] master.AssignmentManager(1502): p0419.mtv.cloudera.com,41017,1397370264982 unassigned znodes=2 of total=2 > 2014-04-12 23:24:55,520 INFO [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-0] master.RegionStates(316): Transitioned {63cdcba1fc55ae6463463ae16f4e454e state=OFFLINE, ts=1397370295503, server=null} to {63cdcba1fc55ae6463463ae16f4e454e state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:55,520 INFO [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-2] master.RegionStates(316): Transitioned {d383980be98665b638fd56bfac97a351 state=OFFLINE, ts=1397370295504, server=null} to {d383980be98665b638fd56bfac97a351 state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,520 INFO [Priority.RpcServer.handler=1,port=39010] regionserver.HRegionServer(3513): Open testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:55,520 INFO [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-2] master.RegionStates(316): Transitioned {f9c185520bca999a753ee3ce0a244f6d state=OFFLINE, ts=1397370295504, server=null} to {f9c185520bca999a753ee3ce0a244f6d state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,521 INFO [Priority.RpcServer.handler=1,port=32877] regionserver.HRegionServer(3513): Open testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:55,521 INFO [Priority.RpcServer.handler=1,port=41017] regionserver.HRegionServer(3513): Open testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:55,525 DEBUG [RS_OPEN_REGION-p0419:39010-1] zookeeper.ZKAssign(832): regionserver:39010-0x14559c215740001, quorum=localhost:53570, baseZNode=/hbase Transitioning a8a68d998d21b00499aca60887ae5aef from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,526 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-1] master.AssignmentManager(1626): Bulk assigning done for p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,526 DEBUG [RS_OPEN_REGION-p0419:41017-0] zookeeper.ZKAssign(832): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioning d383980be98665b638fd56bfac97a351 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,526 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-0] master.AssignmentManager(1626): Bulk assigning done for p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,526 INFO [Priority.RpcServer.handler=1,port=41017] regionserver.HRegionServer(3513): Open testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:55,526 DEBUG [RS_OPEN_REGION-p0419:32877-0] zookeeper.ZKAssign(832): regionserver:32877-0x14559c215740003, quorum=localhost:53570, baseZNode=/hbase Transitioning 63cdcba1fc55ae6463463ae16f4e454e from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,527 DEBUG [RS_OPEN_REGION-p0419:41017-2] zookeeper.ZKAssign(832): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioning f9c185520bca999a753ee3ce0a244f6d from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,527 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-GeneralBulkAssigner-2] master.AssignmentManager(1626): Bulk assigning done for p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,527 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] master.GeneralBulkAssigner(153): bulk assigning total 4 regions to 3 servers, took 23ms, with 4 regions still in transition > 2014-04-12 23:24:55,527 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] master.AssignmentManager(2513): Bulk assigning done > 2014-04-12 23:24:55,535 DEBUG [RS_OPEN_REGION-p0419:39010-1] zookeeper.ZKAssign(907): regionserver:39010-0x14559c215740001, quorum=localhost:53570, baseZNode=/hbase Transitioned node a8a68d998d21b00499aca60887ae5aef from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,535 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:55,536 DEBUG [RS_OPEN_REGION-p0419:39010-1] regionserver.HRegion(4153): Opening region: {ENCODED => a8a68d998d21b00499aca60887ae5aef, NAME => 'testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.', STARTKEY => 'A', ENDKEY => 'B'} > 2014-04-12 23:24:55,536 DEBUG [RS_OPEN_REGION-p0419:39010-1] regionserver.MetricsRegionSourceImpl(64): Creating new MetricsRegionSourceImpl for table testQuarantineMissingHFile a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:55,536 DEBUG [RS_OPEN_REGION-p0419:39010-1] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:55,577 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:55,577 DEBUG [RS_OPEN_REGION-p0419:41017-0] zookeeper.ZKAssign(907): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioned node d383980be98665b638fd56bfac97a351 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,578 DEBUG [RS_OPEN_REGION-p0419:41017-0] regionserver.HRegion(4153): Opening region: {ENCODED => d383980be98665b638fd56bfac97a351, NAME => 'testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.', STARTKEY => 'B', ENDKEY => 'C'} > 2014-04-12 23:24:55,578 DEBUG [RS_OPEN_REGION-p0419:41017-0] regionserver.MetricsRegionSourceImpl(64): Creating new MetricsRegionSourceImpl for table testQuarantineMissingHFile d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:55,579 DEBUG [RS_OPEN_REGION-p0419:41017-0] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:55,594 INFO [StoreOpener-a8a68d998d21b00499aca60887ae5aef-1] compactions.CompactionConfiguration(85): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000 > 2014-04-12 23:24:55,598 DEBUG [RS_OPEN_REGION-p0419:39010-1] regionserver.HRegion(2822): Found 0 recovered edits file(s) under hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:55,600 INFO [RS_OPEN_REGION-p0419:39010-1] regionserver.HRegion(637): Onlined a8a68d998d21b00499aca60887ae5aef; next sequenceid=1 > 2014-04-12 23:24:55,600 DEBUG [RS_OPEN_REGION-p0419:39010-1] zookeeper.ZKAssign(644): regionserver:39010-0x14559c215740001, quorum=localhost:53570, baseZNode=/hbase Attempting to retransition opening state of node a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:55,644 INFO [StoreOpener-d383980be98665b638fd56bfac97a351-1] compactions.CompactionConfiguration(85): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000 > 2014-04-12 23:24:55,648 DEBUG [RS_OPEN_REGION-p0419:41017-0] regionserver.HRegion(2822): Found 0 recovered edits file(s) under hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:55,650 INFO [RS_OPEN_REGION-p0419:41017-0] regionserver.HRegion(637): Onlined d383980be98665b638fd56bfac97a351; next sequenceid=1 > 2014-04-12 23:24:55,650 DEBUG [RS_OPEN_REGION-p0419:41017-0] zookeeper.ZKAssign(644): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Attempting to retransition opening state of node d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:55,657 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:55,657 DEBUG [RS_OPEN_REGION-p0419:32877-0] zookeeper.ZKAssign(907): regionserver:32877-0x14559c215740003, quorum=localhost:53570, baseZNode=/hbase Transitioned node 63cdcba1fc55ae6463463ae16f4e454e from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,658 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:55,658 DEBUG [RS_OPEN_REGION-p0419:41017-2] zookeeper.ZKAssign(907): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioned node f9c185520bca999a753ee3ce0a244f6d from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING > 2014-04-12 23:24:55,658 DEBUG [AM.ZK.Worker-pool2-t11] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENING, server=p0419.mtv.cloudera.com,39010,1397370264935, region=a8a68d998d21b00499aca60887ae5aef, current_state={a8a68d998d21b00499aca60887ae5aef state=PENDING_OPEN, ts=1397370295519, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:55,658 DEBUG [RS_OPEN_REGION-p0419:32877-0] regionserver.HRegion(4153): Opening region: {ENCODED => 63cdcba1fc55ae6463463ae16f4e454e, NAME => 'testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.', STARTKEY => '', ENDKEY => 'A'} > 2014-04-12 23:24:55,658 DEBUG [RS_OPEN_REGION-p0419:41017-2] regionserver.HRegion(4153): Opening region: {ENCODED => f9c185520bca999a753ee3ce0a244f6d, NAME => 'testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.', STARTKEY => 'C', ENDKEY => ''} > 2014-04-12 23:24:55,658 INFO [AM.ZK.Worker-pool2-t11] master.RegionStates(316): Transitioned {a8a68d998d21b00499aca60887ae5aef state=PENDING_OPEN, ts=1397370295519, server=p0419.mtv.cloudera.com,39010,1397370264935} to {a8a68d998d21b00499aca60887ae5aef state=OPENING, ts=1397370295658, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:55,659 DEBUG [RS_OPEN_REGION-p0419:32877-0] regionserver.MetricsRegionSourceImpl(64): Creating new MetricsRegionSourceImpl for table testQuarantineMissingHFile 63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:55,659 DEBUG [RS_OPEN_REGION-p0419:41017-2] regionserver.MetricsRegionSourceImpl(64): Creating new MetricsRegionSourceImpl for table testQuarantineMissingHFile f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:55,659 DEBUG [RS_OPEN_REGION-p0419:32877-0] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:55,659 DEBUG [RS_OPEN_REGION-p0419:41017-2] regionserver.HRegion(542): Instantiated testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:55,694 DEBUG [AM.ZK.Worker-pool2-t13] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENING, server=p0419.mtv.cloudera.com,41017,1397370264982, region=d383980be98665b638fd56bfac97a351, current_state={d383980be98665b638fd56bfac97a351 state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,694 INFO [AM.ZK.Worker-pool2-t13] master.RegionStates(316): Transitioned {d383980be98665b638fd56bfac97a351 state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,41017,1397370264982} to {d383980be98665b638fd56bfac97a351 state=OPENING, ts=1397370295694, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,694 DEBUG [AM.ZK.Worker-pool2-t18] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENING, server=p0419.mtv.cloudera.com,32877,1397370265023, region=63cdcba1fc55ae6463463ae16f4e454e, current_state={63cdcba1fc55ae6463463ae16f4e454e state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:55,694 DEBUG [AM.ZK.Worker-pool2-t10] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENING, server=p0419.mtv.cloudera.com,41017,1397370264982, region=f9c185520bca999a753ee3ce0a244f6d, current_state={f9c185520bca999a753ee3ce0a244f6d state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,694 INFO [PostOpenDeployTasks:d383980be98665b638fd56bfac97a351] regionserver.HRegionServer(1688): Post open deploy tasks for region=testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:55,694 INFO [AM.ZK.Worker-pool2-t18] master.RegionStates(316): Transitioned {63cdcba1fc55ae6463463ae16f4e454e state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,32877,1397370265023} to {63cdcba1fc55ae6463463ae16f4e454e state=OPENING, ts=1397370295694, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:55,694 INFO [PostOpenDeployTasks:a8a68d998d21b00499aca60887ae5aef] regionserver.HRegionServer(1688): Post open deploy tasks for region=testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:55,695 INFO [AM.ZK.Worker-pool2-t10] master.RegionStates(316): Transitioned {f9c185520bca999a753ee3ce0a244f6d state=PENDING_OPEN, ts=1397370295520, server=p0419.mtv.cloudera.com,41017,1397370264982} to {f9c185520bca999a753ee3ce0a244f6d state=OPENING, ts=1397370295695, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,718 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] lock.ZKInterProcessLockBase(328): Released /hbase/table-lock/testQuarantineMissingHFile/write-master:330010000000000 > 2014-04-12 23:24:55,723 INFO [PostOpenDeployTasks:d383980be98665b638fd56bfac97a351] catalog.MetaEditor(464): Updated row testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. with server=p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,723 INFO [PostOpenDeployTasks:d383980be98665b638fd56bfac97a351] regionserver.HRegionServer(1713): Finished post open deploy task for testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:55,726 DEBUG [RS_OPEN_REGION-p0419:41017-0] zookeeper.ZKAssign(832): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioning d383980be98665b638fd56bfac97a351 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,726 INFO [PostOpenDeployTasks:a8a68d998d21b00499aca60887ae5aef] catalog.MetaEditor(464): Updated row testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. with server=p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,726 INFO [PostOpenDeployTasks:a8a68d998d21b00499aca60887ae5aef] regionserver.HRegionServer(1713): Finished post open deploy task for testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:55,727 DEBUG [RS_OPEN_REGION-p0419:39010-1] zookeeper.ZKAssign(832): regionserver:39010-0x14559c215740001, quorum=localhost:53570, baseZNode=/hbase Transitioning a8a68d998d21b00499aca60887ae5aef from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,728 INFO [StoreOpener-f9c185520bca999a753ee3ce0a244f6d-1] compactions.CompactionConfiguration(85): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000 > 2014-04-12 23:24:55,731 DEBUG [RS_OPEN_REGION-p0419:41017-2] regionserver.HRegion(2822): Found 0 recovered edits file(s) under hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:55,732 INFO [RS_OPEN_REGION-p0419:41017-2] regionserver.HRegion(637): Onlined f9c185520bca999a753ee3ce0a244f6d; next sequenceid=1 > 2014-04-12 23:24:55,733 DEBUG [RS_OPEN_REGION-p0419:41017-2] zookeeper.ZKAssign(644): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Attempting to retransition opening state of node f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:55,777 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:55,777 DEBUG [RS_OPEN_REGION-p0419:41017-0] zookeeper.ZKAssign(907): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioned node d383980be98665b638fd56bfac97a351 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,777 DEBUG [RS_OPEN_REGION-p0419:41017-0] handler.OpenRegionHandler(389): Transitioned d383980be98665b638fd56bfac97a351 to OPENED in zk on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,777 DEBUG [RS_OPEN_REGION-p0419:41017-0] handler.OpenRegionHandler(189): Opened testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,786 INFO [StoreOpener-63cdcba1fc55ae6463463ae16f4e454e-1] compactions.CompactionConfiguration(85): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000 > 2014-04-12 23:24:55,789 DEBUG [RS_OPEN_REGION-p0419:32877-0] regionserver.HRegion(2822): Found 0 recovered edits file(s) under hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:55,792 INFO [RS_OPEN_REGION-p0419:32877-0] regionserver.HRegion(637): Onlined 63cdcba1fc55ae6463463ae16f4e454e; next sequenceid=1 > 2014-04-12 23:24:55,792 DEBUG [RS_OPEN_REGION-p0419:32877-0] zookeeper.ZKAssign(644): regionserver:32877-0x14559c215740003, quorum=localhost:53570, baseZNode=/hbase Attempting to retransition opening state of node 63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:55,827 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:55,827 DEBUG [RS_OPEN_REGION-p0419:39010-1] zookeeper.ZKAssign(907): regionserver:39010-0x14559c215740001, quorum=localhost:53570, baseZNode=/hbase Transitioned node a8a68d998d21b00499aca60887ae5aef from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,827 DEBUG [RS_OPEN_REGION-p0419:39010-1] handler.OpenRegionHandler(389): Transitioned a8a68d998d21b00499aca60887ae5aef to OPENED in zk on p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,827 DEBUG [AM.ZK.Worker-pool2-t15] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENED, server=p0419.mtv.cloudera.com,41017,1397370264982, region=d383980be98665b638fd56bfac97a351, current_state={d383980be98665b638fd56bfac97a351 state=OPENING, ts=1397370295694, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,827 DEBUG [RS_OPEN_REGION-p0419:39010-1] handler.OpenRegionHandler(189): Opened testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. on p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,827 INFO [AM.ZK.Worker-pool2-t15] master.RegionStates(316): Transitioned {d383980be98665b638fd56bfac97a351 state=OPENING, ts=1397370295694, server=p0419.mtv.cloudera.com,41017,1397370264982} to {d383980be98665b638fd56bfac97a351 state=OPEN, ts=1397370295827, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,828 INFO [PostOpenDeployTasks:f9c185520bca999a753ee3ce0a244f6d] regionserver.HRegionServer(1688): Post open deploy tasks for region=testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:55,828 DEBUG [AM.ZK.Worker-pool2-t15] handler.OpenedRegionHandler(149): Handling OPENED of d383980be98665b638fd56bfac97a351 from p0419.mtv.cloudera.com,41017,1397370264982; deleting unassigned node > 2014-04-12 23:24:55,828 INFO [PostOpenDeployTasks:63cdcba1fc55ae6463463ae16f4e454e] regionserver.HRegionServer(1688): Post open deploy tasks for region=testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:55,828 DEBUG [AM.ZK.Worker-pool2-t1] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENED, server=p0419.mtv.cloudera.com,39010,1397370264935, region=a8a68d998d21b00499aca60887ae5aef, current_state={a8a68d998d21b00499aca60887ae5aef state=OPENING, ts=1397370295658, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:55,828 INFO [AM.ZK.Worker-pool2-t1] master.RegionStates(316): Transitioned {a8a68d998d21b00499aca60887ae5aef state=OPENING, ts=1397370295658, server=p0419.mtv.cloudera.com,39010,1397370264935} to {a8a68d998d21b00499aca60887ae5aef state=OPEN, ts=1397370295828, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:55,829 DEBUG [AM.ZK.Worker-pool2-t1] handler.OpenedRegionHandler(149): Handling OPENED of a8a68d998d21b00499aca60887ae5aef from p0419.mtv.cloudera.com,39010,1397370264935; deleting unassigned node > 2014-04-12 23:24:55,844 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:55,844 DEBUG [AM.ZK.Worker-pool2-t15] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node d383980be98665b638fd56bfac97a351 in expected state RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,844 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/region-in-transition > 2014-04-12 23:24:55,844 DEBUG [AM.ZK.Worker-pool2-t15] master.AssignmentManager$4(1173): Znode testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. deleted, state: {d383980be98665b638fd56bfac97a351 state=OPEN, ts=1397370295827, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,844 INFO [AM.ZK.Worker-pool2-t15] master.RegionStates(377): Onlined d383980be98665b638fd56bfac97a351 on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,848 INFO [PostOpenDeployTasks:f9c185520bca999a753ee3ce0a244f6d] catalog.MetaEditor(464): Updated row testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. with server=p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,848 INFO [PostOpenDeployTasks:63cdcba1fc55ae6463463ae16f4e454e] catalog.MetaEditor(464): Updated row testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. with server=p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,849 INFO [PostOpenDeployTasks:63cdcba1fc55ae6463463ae16f4e454e] regionserver.HRegionServer(1713): Finished post open deploy task for testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:55,849 INFO [PostOpenDeployTasks:f9c185520bca999a753ee3ce0a244f6d] regionserver.HRegionServer(1713): Finished post open deploy task for testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:55,850 DEBUG [RS_OPEN_REGION-p0419:32877-0] zookeeper.ZKAssign(832): regionserver:32877-0x14559c215740003, quorum=localhost:53570, baseZNode=/hbase Transitioning 63cdcba1fc55ae6463463ae16f4e454e from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,850 DEBUG [RS_OPEN_REGION-p0419:41017-2] zookeeper.ZKAssign(832): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioning f9c185520bca999a753ee3ce0a244f6d from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,869 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:55,869 DEBUG [AM.ZK.Worker-pool2-t1] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node a8a68d998d21b00499aca60887ae5aef in expected state RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,869 DEBUG [AM.ZK.Worker-pool2-t1] master.AssignmentManager$4(1173): Znode testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. deleted, state: {a8a68d998d21b00499aca60887ae5aef state=OPEN, ts=1397370295828, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:55,869 INFO [AM.ZK.Worker-pool2-t1] master.RegionStates(377): Onlined a8a68d998d21b00499aca60887ae5aef on p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:55,910 DEBUG [RS_OPEN_REGION-p0419:32877-0] zookeeper.ZKAssign(907): regionserver:32877-0x14559c215740003, quorum=localhost:53570, baseZNode=/hbase Transitioned node 63cdcba1fc55ae6463463ae16f4e454e from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,910 DEBUG [RS_OPEN_REGION-p0419:41017-2] zookeeper.ZKAssign(907): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioned node f9c185520bca999a753ee3ce0a244f6d from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,911 DEBUG [RS_OPEN_REGION-p0419:41017-2] handler.OpenRegionHandler(389): Transitioned f9c185520bca999a753ee3ce0a244f6d to OPENED in zk on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,910 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:55,911 DEBUG [RS_OPEN_REGION-p0419:41017-2] handler.OpenRegionHandler(189): Opened testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:55,910 DEBUG [RS_OPEN_REGION-p0419:32877-0] handler.OpenRegionHandler(389): Transitioned 63cdcba1fc55ae6463463ae16f4e454e to OPENED in zk on p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,911 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:55,911 DEBUG [RS_OPEN_REGION-p0419:32877-0] handler.OpenRegionHandler(189): Opened testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. on p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,912 DEBUG [AM.ZK.Worker-pool2-t7] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENED, server=p0419.mtv.cloudera.com,32877,1397370265023, region=63cdcba1fc55ae6463463ae16f4e454e, current_state={63cdcba1fc55ae6463463ae16f4e454e state=OPENING, ts=1397370295694, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:55,912 INFO [AM.ZK.Worker-pool2-t7] master.RegionStates(316): Transitioned {63cdcba1fc55ae6463463ae16f4e454e state=OPENING, ts=1397370295694, server=p0419.mtv.cloudera.com,32877,1397370265023} to {63cdcba1fc55ae6463463ae16f4e454e state=OPEN, ts=1397370295912, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:55,912 DEBUG [AM.ZK.Worker-pool2-t20] master.AssignmentManager(790): Handling RS_ZK_REGION_OPENED, server=p0419.mtv.cloudera.com,41017,1397370264982, region=f9c185520bca999a753ee3ce0a244f6d, current_state={f9c185520bca999a753ee3ce0a244f6d state=OPENING, ts=1397370295695, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,912 DEBUG [AM.ZK.Worker-pool2-t7] handler.OpenedRegionHandler(149): Handling OPENED of 63cdcba1fc55ae6463463ae16f4e454e from p0419.mtv.cloudera.com,32877,1397370265023; deleting unassigned node > 2014-04-12 23:24:55,912 INFO [AM.ZK.Worker-pool2-t20] master.RegionStates(316): Transitioned {f9c185520bca999a753ee3ce0a244f6d state=OPENING, ts=1397370295695, server=p0419.mtv.cloudera.com,41017,1397370264982} to {f9c185520bca999a753ee3ce0a244f6d state=OPEN, ts=1397370295912, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,913 DEBUG [AM.ZK.Worker-pool2-t20] handler.OpenedRegionHandler(149): Handling OPENED of f9c185520bca999a753ee3ce0a244f6d from p0419.mtv.cloudera.com,41017,1397370264982; deleting unassigned node > 2014-04-12 23:24:55,927 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:55,927 DEBUG [AM.ZK.Worker-pool2-t7] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node 63cdcba1fc55ae6463463ae16f4e454e in expected state RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,927 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/region-in-transition > 2014-04-12 23:24:55,927 DEBUG [AM.ZK.Worker-pool2-t7] master.AssignmentManager$4(1173): Znode testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. deleted, state: {63cdcba1fc55ae6463463ae16f4e454e state=OPEN, ts=1397370295912, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:55,927 INFO [AM.ZK.Worker-pool2-t7] master.RegionStates(377): Onlined 63cdcba1fc55ae6463463ae16f4e454e on p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:55,935 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:55,935 DEBUG [AM.ZK.Worker-pool2-t20] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node f9c185520bca999a753ee3ce0a244f6d in expected state RS_ZK_REGION_OPENED > 2014-04-12 23:24:55,936 DEBUG [AM.ZK.Worker-pool2-t20] master.AssignmentManager$4(1173): Znode testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. deleted, state: {f9c185520bca999a753ee3ce0a244f6d state=OPEN, ts=1397370295912, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:55,936 INFO [AM.ZK.Worker-pool2-t20] master.RegionStates(377): Onlined f9c185520bca999a753ee3ce0a244f6d on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:56,206 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=catalogtracker-on-hconnection-0x1ae9e1aa connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:56,206 DEBUG [Thread-587] catalog.CatalogTracker(193): Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@55a56f72 > 2014-04-12 23:24:56,219 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:56,219 DEBUG [Thread-587] zookeeper.ZKUtil(428): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Set watcher on existing znode=/hbase/meta-region-server > 2014-04-12 23:24:56,220 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): catalogtracker-on-hconnection-0x1ae9e1aa-0x14559c215740041 connected > 2014-04-12 23:24:56,225 DEBUG [Thread-587] catalog.CatalogTracker(209): Stopping catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@55a56f72 > 2014-04-12 23:24:56,263 DEBUG [Thread-587] client.ClientScanner(257): Advancing internal scanner to startKey at 'A' > 2014-04-12 23:24:56,267 DEBUG [Thread-587] client.ClientScanner(257): Advancing internal scanner to startKey at 'B' > 2014-04-12 23:24:56,270 DEBUG [Thread-587] client.ClientScanner(257): Advancing internal scanner to startKey at 'C' > 2014-04-12 23:24:56,273 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=catalogtracker-on-hconnection-0x1ae9e1aa connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:56,274 DEBUG [Thread-587] catalog.CatalogTracker(193): Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@7c28bed5 > 2014-04-12 23:24:56,294 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:56,294 DEBUG [Thread-587] zookeeper.ZKUtil(428): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Set watcher on existing znode=/hbase/meta-region-server > 2014-04-12 23:24:56,295 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): catalogtracker-on-hconnection-0x1ae9e1aa-0x14559c215740042 connected > 2014-04-12 23:24:56,320 INFO [Priority.RpcServer.handler=0,port=32877] regionserver.HRegionServer(3661): Flushing testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:56,322 DEBUG [Priority.RpcServer.handler=0,port=32877] regionserver.HRegion(1513): Started memstore flush for testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e., current region memstore size 320 > 2014-04-12 23:24:56,460 INFO [IPC Server handler 1 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741872_1048{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,461 INFO [IPC Server handler 0 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741872_1048{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,462 INFO [IPC Server handler 7 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741872_1048 size 1042 > 2014-04-12 23:24:56,502 INFO [Priority.RpcServer.handler=0,port=32877] regionserver.DefaultStoreFlusher(88): Flushed, sequenceid=15, memsize=320, hasBloomFilter=true, into tmp file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/.tmp/57a07eaac97e4acd8dc04e08d1950adc > 2014-04-12 23:24:56,514 DEBUG [Priority.RpcServer.handler=0,port=32877] regionserver.HRegionFileSystem(338): Committing store file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/.tmp/57a07eaac97e4acd8dc04e08d1950adc as hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/fam/57a07eaac97e4acd8dc04e08d1950adc > 2014-04-12 23:24:56,584 INFO [Priority.RpcServer.handler=0,port=32877] regionserver.HStore(764): Added hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/fam/57a07eaac97e4acd8dc04e08d1950adc, entries=2, sequenceid=15, filesize=1.0 K > 2014-04-12 23:24:56,584 INFO [Priority.RpcServer.handler=0,port=32877] regionserver.HRegion(1660): Finished memstore flush of ~320/320, currentsize=0/0 for region testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. in 262ms, sequenceid=15, compaction requested=false > 2014-04-12 23:24:56,586 INFO [Priority.RpcServer.handler=0,port=39010] regionserver.HRegionServer(3661): Flushing testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:56,589 DEBUG [Priority.RpcServer.handler=0,port=39010] regionserver.HRegion(1513): Started memstore flush for testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef., current region memstore size 320 > 2014-04-12 23:24:56,668 INFO [IPC Server handler 7 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741873_1049{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,669 INFO [IPC Server handler 2 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741873_1049{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,669 INFO [IPC Server handler 8 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741873_1049{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,677 INFO [Priority.RpcServer.handler=0,port=39010] regionserver.DefaultStoreFlusher(88): Flushed, sequenceid=10, memsize=320, hasBloomFilter=true, into tmp file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef/.tmp/0ce0a00435f64a02856bfe0fb779093b > 2014-04-12 23:24:56,688 DEBUG [Priority.RpcServer.handler=0,port=39010] regionserver.HRegionFileSystem(338): Committing store file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef/.tmp/0ce0a00435f64a02856bfe0fb779093b as hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef/fam/0ce0a00435f64a02856bfe0fb779093b > 2014-04-12 23:24:56,701 INFO [Priority.RpcServer.handler=0,port=39010] regionserver.HStore(764): Added hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef/fam/0ce0a00435f64a02856bfe0fb779093b, entries=2, sequenceid=10, filesize=1.0 K > 2014-04-12 23:24:56,701 INFO [Priority.RpcServer.handler=0,port=39010] regionserver.HRegion(1660): Finished memstore flush of ~320/320, currentsize=0/0 for region testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. in 112ms, sequenceid=10, compaction requested=false > 2014-04-12 23:24:56,702 INFO [Priority.RpcServer.handler=1,port=41017] regionserver.HRegionServer(3661): Flushing testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:56,702 DEBUG [Priority.RpcServer.handler=1,port=41017] regionserver.HRegion(1513): Started memstore flush for testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351., current region memstore size 320 > 2014-04-12 23:24:56,734 INFO [IPC Server handler 8 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741874_1050{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,734 INFO [IPC Server handler 5 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741874_1050{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,735 INFO [IPC Server handler 9 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741874_1050{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-45b6fa92-7966-4203-8e5a-f8115f53e1ae:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-34a4a47f-8a95-461c-8633-2a7fd583b8d9:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-80866ac4-36df-41f3-a856-da7636fa89a3:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:56,744 INFO [Priority.RpcServer.handler=1,port=41017] regionserver.DefaultStoreFlusher(88): Flushed, sequenceid=14, memsize=320, hasBloomFilter=true, into tmp file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/.tmp/9dd79f30f29e4cfeaa46f6e20b32e078 > 2014-04-12 23:24:56,754 DEBUG [Priority.RpcServer.handler=1,port=41017] regionserver.HRegionFileSystem(338): Committing store file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/.tmp/9dd79f30f29e4cfeaa46f6e20b32e078 as hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/fam/9dd79f30f29e4cfeaa46f6e20b32e078 > 2014-04-12 23:24:56,786 INFO [Priority.RpcServer.handler=1,port=41017] regionserver.HStore(764): Added hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/fam/9dd79f30f29e4cfeaa46f6e20b32e078, entries=2, sequenceid=14, filesize=1.0 K > 2014-04-12 23:24:56,786 INFO [Priority.RpcServer.handler=1,port=41017] regionserver.HRegion(1660): Finished memstore flush of ~320/320, currentsize=0/0 for region testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. in 84ms, sequenceid=14, compaction requested=false > 2014-04-12 23:24:56,787 INFO [Priority.RpcServer.handler=0,port=41017] regionserver.HRegionServer(3661): Flushing testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:56,787 DEBUG [Priority.RpcServer.handler=0,port=41017] regionserver.HRegion(1513): Started memstore flush for testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d., current region memstore size 320 > 2014-04-12 23:24:57,027 INFO [IPC Server handler 9 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53997 is added to blk_1073741875_1051{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-0cf6df80-0db5-43f5-bbc4-a7092d736c08:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-a192707c-27de-4afa-9948-d58a0f0df6bf:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-b2725947-b15b-4c3a-be84-aedc2a57e25f:NORMAL|RBW]]} size 0 > 2014-04-12 23:24:57,028 INFO [IPC Server handler 6 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49422 is added to blk_1073741875_1051 size 1042 > 2014-04-12 23:24:57,029 INFO [IPC Server handler 4 on 50919] blockmanagement.BlockManager(2339): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33353 is added to blk_1073741875_1051 size 1042 > 2014-04-12 23:24:57,077 INFO [Priority.RpcServer.handler=0,port=41017] regionserver.DefaultStoreFlusher(88): Flushed, sequenceid=15, memsize=320, hasBloomFilter=true, into tmp file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d/.tmp/404e9e4c06b54305a0831dc4749d9a5f > 2014-04-12 23:24:57,089 DEBUG [Priority.RpcServer.handler=0,port=41017] regionserver.HRegionFileSystem(338): Committing store file hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d/.tmp/404e9e4c06b54305a0831dc4749d9a5f as hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d/fam/404e9e4c06b54305a0831dc4749d9a5f > 2014-04-12 23:24:57,153 INFO [Priority.RpcServer.handler=0,port=41017] regionserver.HStore(764): Added hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d/fam/404e9e4c06b54305a0831dc4749d9a5f, entries=2, sequenceid=15, filesize=1.0 K > 2014-04-12 23:24:57,154 INFO [Priority.RpcServer.handler=0,port=41017] regionserver.HRegion(1660): Finished memstore flush of ~320/320, currentsize=0/0 for region testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. in 367ms, sequenceid=15, compaction requested=false > 2014-04-12 23:24:57,154 DEBUG [Thread-587] catalog.CatalogTracker(209): Stopping catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@7c28bed5 > 2014-04-12 23:24:57,176 INFO [Thread-587] client.HBaseAdmin$5(909): Started disable of testQuarantineMissingHFile > 2014-04-12 23:24:57,178 INFO [RpcServer.handler=0,port=33001] master.HMaster(1980): Client=jenkins//172.29.122.11 disable testQuarantineMissingHFile > 2014-04-12 23:24:57,219 DEBUG [RpcServer.handler=0,port=33001] lock.ZKInterProcessLockBase(226): Acquired a lock for /hbase/table-lock/testQuarantineMissingHFile/write-master:330010000000001 > 2014-04-12 23:24:57,252 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DisableTableHandler(130): Attempting to disable table testQuarantineMissingHFile > 2014-04-12 23:24:57,253 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=catalogtracker-on-hconnection-0x1ae9e1aa connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:57,254 DEBUG [Thread-587] catalog.CatalogTracker(193): Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@17dc9229 > 2014-04-12 23:24:57,277 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DisableTableHandler(174): Offlining 4 regions. > 2014-04-12 23:24:57,278 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-0] master.AssignmentManager(2232): Starting unassign of testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. (offlining), current state: {63cdcba1fc55ae6463463ae16f4e454e state=OPEN, ts=1397370295927, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:57,278 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-2] master.AssignmentManager(2232): Starting unassign of testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. (offlining), current state: {d383980be98665b638fd56bfac97a351 state=OPEN, ts=1397370295844, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,278 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-2] zookeeper.ZKAssign(527): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Creating unassigned node d383980be98665b638fd56bfac97a351 in a CLOSING state > 2014-04-12 23:24:57,278 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-1] master.AssignmentManager(2232): Starting unassign of testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. (offlining), current state: {a8a68d998d21b00499aca60887ae5aef state=OPEN, ts=1397370295869, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:57,278 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-1] zookeeper.ZKAssign(527): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Creating unassigned node a8a68d998d21b00499aca60887ae5aef in a CLOSING state > 2014-04-12 23:24:57,278 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-3] master.AssignmentManager(2232): Starting unassign of testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. (offlining), current state: {f9c185520bca999a753ee3ce0a244f6d state=OPEN, ts=1397370295936, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,278 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-0] zookeeper.ZKAssign(527): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Creating unassigned node 63cdcba1fc55ae6463463ae16f4e454e in a CLOSING state > 2014-04-12 23:24:57,279 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-3] zookeeper.ZKAssign(527): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Creating unassigned node f9c185520bca999a753ee3ce0a244f6d in a CLOSING state > 2014-04-12 23:24:57,311 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:57,312 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): catalogtracker-on-hconnection-0x1ae9e1aa-0x14559c215740043 connected > 2014-04-12 23:24:57,319 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/region-in-transition > 2014-04-12 23:24:57,319 DEBUG [Thread-587] zookeeper.ZKUtil(428): catalogtracker-on-hconnection-0x1ae9e1aa-0x14559c215740043, quorum=localhost:53570, baseZNode=/hbase Set watcher on existing znode=/hbase/meta-region-server > 2014-04-12 23:24:57,320 INFO [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-2] master.RegionStates(316): Transitioned {d383980be98665b638fd56bfac97a351 state=OPEN, ts=1397370295844, server=p0419.mtv.cloudera.com,41017,1397370264982} to {d383980be98665b638fd56bfac97a351 state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,320 INFO [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-0] master.RegionStates(316): Transitioned {63cdcba1fc55ae6463463ae16f4e454e state=OPEN, ts=1397370295927, server=p0419.mtv.cloudera.com,32877,1397370265023} to {63cdcba1fc55ae6463463ae16f4e454e state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:57,320 INFO [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-1] master.RegionStates(316): Transitioned {a8a68d998d21b00499aca60887ae5aef state=OPEN, ts=1397370295869, server=p0419.mtv.cloudera.com,39010,1397370264935} to {a8a68d998d21b00499aca60887ae5aef state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:57,320 INFO [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-3] master.RegionStates(316): Transitioned {f9c185520bca999a753ee3ce0a244f6d state=OPEN, ts=1397370295936, server=p0419.mtv.cloudera.com,41017,1397370264982} to {f9c185520bca999a753ee3ce0a244f6d state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,320 INFO [Priority.RpcServer.handler=0,port=41017] regionserver.HRegionServer(3635): Close d383980be98665b638fd56bfac97a351, via zk=yes, znode version=0, on null > 2014-04-12 23:24:57,320 INFO [Priority.RpcServer.handler=1,port=32877] regionserver.HRegionServer(3635): Close 63cdcba1fc55ae6463463ae16f4e454e, via zk=yes, znode version=0, on null > 2014-04-12 23:24:57,321 INFO [Priority.RpcServer.handler=1,port=39010] regionserver.HRegionServer(3635): Close a8a68d998d21b00499aca60887ae5aef, via zk=yes, znode version=0, on null > 2014-04-12 23:24:57,321 INFO [Priority.RpcServer.handler=1,port=41017] regionserver.HRegionServer(3635): Close f9c185520bca999a753ee3ce0a244f6d, via zk=yes, znode version=0, on null > 2014-04-12 23:24:57,321 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-2] master.AssignmentManager(1674): Sent CLOSE to p0419.mtv.cloudera.com,41017,1397370264982 for region testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:57,321 DEBUG [RS_CLOSE_REGION-p0419:41017-1] handler.CloseRegionHandler(125): Processing close of testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:57,321 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-1] master.AssignmentManager(1674): Sent CLOSE to p0419.mtv.cloudera.com,39010,1397370264935 for region testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:57,321 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-0] master.AssignmentManager(1674): Sent CLOSE to p0419.mtv.cloudera.com,32877,1397370265023 for region testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:57,321 DEBUG [RS_CLOSE_REGION-p0419:39010-1] handler.CloseRegionHandler(125): Processing close of testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:57,321 DEBUG [RS_CLOSE_REGION-p0419:41017-2] handler.CloseRegionHandler(125): Processing close of testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:57,321 DEBUG [RS_CLOSE_REGION-p0419:32877-1] handler.CloseRegionHandler(125): Processing close of testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:57,321 DEBUG [p0419.mtv.cloudera.com,33001,1397370264247-org.apache.hadoop.hbase.master.handler.DisableTableHandler$BulkDisabler-3] master.AssignmentManager(1674): Sent CLOSE to p0419.mtv.cloudera.com,41017,1397370264982 for region testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:57,322 DEBUG [RS_CLOSE_REGION-p0419:41017-1] regionserver.HRegion(988): Closing testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.: disabling compactions & flushes > 2014-04-12 23:24:57,323 DEBUG [RS_CLOSE_REGION-p0419:41017-1] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:57,323 DEBUG [RS_CLOSE_REGION-p0419:39010-1] regionserver.HRegion(988): Closing testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.: disabling compactions & flushes > 2014-04-12 23:24:57,323 DEBUG [RS_CLOSE_REGION-p0419:39010-1] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:57,323 DEBUG [RS_CLOSE_REGION-p0419:41017-2] regionserver.HRegion(988): Closing testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.: disabling compactions & flushes > 2014-04-12 23:24:57,323 DEBUG [RS_CLOSE_REGION-p0419:32877-1] regionserver.HRegion(988): Closing testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.: disabling compactions & flushes > 2014-04-12 23:24:57,323 DEBUG [RS_CLOSE_REGION-p0419:41017-2] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:57,323 DEBUG [RS_CLOSE_REGION-p0419:32877-1] regionserver.HRegion(1010): Updates disabled for region testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:57,327 INFO [StoreCloserThread-testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.-1] regionserver.HStore(661): Closed fam > 2014-04-12 23:24:57,327 INFO [StoreCloserThread-testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.-1] regionserver.HStore(661): Closed fam > 2014-04-12 23:24:57,328 INFO [RS_CLOSE_REGION-p0419:39010-1] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:57,328 DEBUG [RS_CLOSE_REGION-p0419:39010-1] zookeeper.ZKAssign(832): regionserver:39010-0x14559c215740001, quorum=localhost:53570, baseZNode=/hbase Transitioning a8a68d998d21b00499aca60887ae5aef from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,328 INFO [RS_CLOSE_REGION-p0419:41017-1] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:57,330 DEBUG [RS_CLOSE_REGION-p0419:41017-1] zookeeper.ZKAssign(832): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioning f9c185520bca999a753ee3ce0a244f6d from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,330 INFO [StoreCloserThread-testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.-1] regionserver.HStore(661): Closed fam > 2014-04-12 23:24:57,330 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DisableTableHandler$BulkDisabler(230): Disable waiting until done; 300000 ms remaining; [{ENCODED => 63cdcba1fc55ae6463463ae16f4e454e, NAME => 'testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.', STARTKEY => '', ENDKEY => 'A'}, {ENCODED => a8a68d998d21b00499aca60887ae5aef, NAME => 'testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.', STARTKEY => 'A', ENDKEY => 'B'}, {ENCODED => d383980be98665b638fd56bfac97a351, NAME => 'testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.', STARTKEY => 'B', ENDKEY => 'C'}, {ENCODED => f9c185520bca999a753ee3ce0a244f6d, NAME => 'testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.', STARTKEY => 'C', ENDKEY => ''}] > 2014-04-12 23:24:57,330 INFO [RS_CLOSE_REGION-p0419:32877-1] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:57,330 INFO [StoreCloserThread-testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.-1] regionserver.HStore(661): Closed fam > 2014-04-12 23:24:57,331 DEBUG [RS_CLOSE_REGION-p0419:32877-1] zookeeper.ZKAssign(832): regionserver:32877-0x14559c215740003, quorum=localhost:53570, baseZNode=/hbase Transitioning 63cdcba1fc55ae6463463ae16f4e454e from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,331 DEBUG [Thread-587] catalog.CatalogTracker(209): Stopping catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@17dc9229 > 2014-04-12 23:24:57,331 INFO [RS_CLOSE_REGION-p0419:41017-2] regionserver.HRegion(1068): Closed testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:57,331 DEBUG [RS_CLOSE_REGION-p0419:41017-2] zookeeper.ZKAssign(832): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioning d383980be98665b638fd56bfac97a351 from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,381 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DisableTableHandler$BulkDisabler(230): Disable waiting until done; 299947 ms remaining; [{ENCODED => 63cdcba1fc55ae6463463ae16f4e454e, NAME => 'testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.', STARTKEY => '', ENDKEY => 'A'}, {ENCODED => a8a68d998d21b00499aca60887ae5aef, NAME => 'testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.', STARTKEY => 'A', ENDKEY => 'B'}, {ENCODED => d383980be98665b638fd56bfac97a351, NAME => 'testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.', STARTKEY => 'B', ENDKEY => 'C'}, {ENCODED => f9c185520bca999a753ee3ce0a244f6d, NAME => 'testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.', STARTKEY => 'C', ENDKEY => ''}] > 2014-04-12 23:24:57,385 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:57,385 DEBUG [RS_CLOSE_REGION-p0419:39010-1] zookeeper.ZKAssign(907): regionserver:39010-0x14559c215740001, quorum=localhost:53570, baseZNode=/hbase Transitioned node a8a68d998d21b00499aca60887ae5aef from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,386 DEBUG [RS_CLOSE_REGION-p0419:39010-1] handler.CloseRegionHandler(168): Set closed state in zk for testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. on p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:57,386 DEBUG [RS_CLOSE_REGION-p0419:39010-1] handler.CloseRegionHandler(176): Closed testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:57,402 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:57,402 DEBUG [RS_CLOSE_REGION-p0419:41017-1] zookeeper.ZKAssign(907): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioned node f9c185520bca999a753ee3ce0a244f6d from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,402 DEBUG [RS_CLOSE_REGION-p0419:41017-1] handler.CloseRegionHandler(168): Set closed state in zk for testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:57,402 DEBUG [RS_CLOSE_REGION-p0419:41017-1] handler.CloseRegionHandler(176): Closed testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:57,402 DEBUG [AM.ZK.Worker-pool2-t2] master.AssignmentManager(790): Handling RS_ZK_REGION_CLOSED, server=p0419.mtv.cloudera.com,39010,1397370264935, region=a8a68d998d21b00499aca60887ae5aef, current_state={a8a68d998d21b00499aca60887ae5aef state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:57,403 DEBUG [AM.ZK.Worker-pool2-t2] handler.ClosedRegionHandler(92): Handling CLOSED event for a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:57,403 DEBUG [Thread-587] client.HBaseAdmin(948): Sleeping= 100ms, waiting for all regions to be disabled in testQuarantineMissingHFile > 2014-04-12 23:24:57,403 DEBUG [AM.ZK.Worker-pool2-t2] master.AssignmentManager(1374): Table being disabled so deleting ZK node and removing from regions in transition, skipping assignment of region testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. > 2014-04-12 23:24:57,410 DEBUG [RS_CLOSE_REGION-p0419:32877-1] zookeeper.ZKAssign(907): regionserver:32877-0x14559c215740003, quorum=localhost:53570, baseZNode=/hbase Transitioned node 63cdcba1fc55ae6463463ae16f4e454e from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,410 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:57,410 DEBUG [AM.ZK.Worker-pool2-t4] master.AssignmentManager(790): Handling RS_ZK_REGION_CLOSED, server=p0419.mtv.cloudera.com,41017,1397370264982, region=f9c185520bca999a753ee3ce0a244f6d, current_state={f9c185520bca999a753ee3ce0a244f6d state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,410 DEBUG [RS_CLOSE_REGION-p0419:32877-1] handler.CloseRegionHandler(168): Set closed state in zk for testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. on p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:57,411 DEBUG [AM.ZK.Worker-pool2-t4] handler.ClosedRegionHandler(92): Handling CLOSED event for f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:57,411 DEBUG [RS_CLOSE_REGION-p0419:32877-1] handler.CloseRegionHandler(176): Closed testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:57,411 DEBUG [AM.ZK.Worker-pool2-t4] master.AssignmentManager(1374): Table being disabled so deleting ZK node and removing from regions in transition, skipping assignment of region testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. > 2014-04-12 23:24:57,418 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/region-in-transition/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:57,418 DEBUG [RS_CLOSE_REGION-p0419:41017-2] zookeeper.ZKAssign(907): regionserver:41017-0x14559c215740002, quorum=localhost:53570, baseZNode=/hbase Transitioned node d383980be98665b638fd56bfac97a351 from M_ZK_REGION_CLOSING to RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,419 DEBUG [AM.ZK.Worker-pool2-t12] master.AssignmentManager(790): Handling RS_ZK_REGION_CLOSED, server=p0419.mtv.cloudera.com,32877,1397370265023, region=63cdcba1fc55ae6463463ae16f4e454e, current_state={63cdcba1fc55ae6463463ae16f4e454e state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:57,419 DEBUG [RS_CLOSE_REGION-p0419:41017-2] handler.CloseRegionHandler(168): Set closed state in zk for testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. on p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:57,419 DEBUG [AM.ZK.Worker-pool2-t12] handler.ClosedRegionHandler(92): Handling CLOSED event for 63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:57,419 DEBUG [RS_CLOSE_REGION-p0419:41017-2] handler.CloseRegionHandler(176): Closed testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:57,419 DEBUG [AM.ZK.Worker-pool2-t12] master.AssignmentManager(1374): Table being disabled so deleting ZK node and removing from regions in transition, skipping assignment of region testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. > 2014-04-12 23:24:57,427 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:57,427 DEBUG [AM.ZK.Worker-pool2-t2] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node a8a68d998d21b00499aca60887ae5aef in expected state RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,427 DEBUG [AM.ZK.Worker-pool2-t14] master.AssignmentManager(790): Handling RS_ZK_REGION_CLOSED, server=p0419.mtv.cloudera.com,41017,1397370264982, region=d383980be98665b638fd56bfac97a351, current_state={d383980be98665b638fd56bfac97a351 state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,427 INFO [AM.ZK.Worker-pool2-t2] master.RegionStates(316): Transitioned {a8a68d998d21b00499aca60887ae5aef state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,39010,1397370264935} to {a8a68d998d21b00499aca60887ae5aef state=OFFLINE, ts=1397370297427, server=p0419.mtv.cloudera.com,39010,1397370264935} > 2014-04-12 23:24:57,427 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/region-in-transition > 2014-04-12 23:24:57,427 INFO [AM.ZK.Worker-pool2-t2] master.RegionStates(457): Offlined a8a68d998d21b00499aca60887ae5aef from p0419.mtv.cloudera.com,39010,1397370264935 > 2014-04-12 23:24:57,428 DEBUG [AM.ZK.Worker-pool2-t14] handler.ClosedRegionHandler(92): Handling CLOSED event for d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:57,428 DEBUG [AM.ZK.Worker-pool2-t14] master.AssignmentManager(1374): Table being disabled so deleting ZK node and removing from regions in transition, skipping assignment of region testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. > 2014-04-12 23:24:57,431 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DisableTableHandler$BulkDisabler(230): Disable waiting until done; 299897 ms remaining; [{ENCODED => 63cdcba1fc55ae6463463ae16f4e454e, NAME => 'testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.', STARTKEY => '', ENDKEY => 'A'}, {ENCODED => d383980be98665b638fd56bfac97a351, NAME => 'testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.', STARTKEY => 'B', ENDKEY => 'C'}, {ENCODED => f9c185520bca999a753ee3ce0a244f6d, NAME => 'testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.', STARTKEY => 'C', ENDKEY => ''}] > 2014-04-12 23:24:57,435 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:57,435 DEBUG [AM.ZK.Worker-pool2-t4] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node f9c185520bca999a753ee3ce0a244f6d in expected state RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,435 INFO [AM.ZK.Worker-pool2-t4] master.RegionStates(316): Transitioned {f9c185520bca999a753ee3ce0a244f6d state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,41017,1397370264982} to {f9c185520bca999a753ee3ce0a244f6d state=OFFLINE, ts=1397370297435, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,436 INFO [AM.ZK.Worker-pool2-t4] master.RegionStates(457): Offlined f9c185520bca999a753ee3ce0a244f6d from p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:57,444 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:57,444 DEBUG [AM.ZK.Worker-pool2-t12] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node 63cdcba1fc55ae6463463ae16f4e454e in expected state RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,444 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/region-in-transition > 2014-04-12 23:24:57,444 INFO [AM.ZK.Worker-pool2-t12] master.RegionStates(316): Transitioned {63cdcba1fc55ae6463463ae16f4e454e state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,32877,1397370265023} to {63cdcba1fc55ae6463463ae16f4e454e state=OFFLINE, ts=1397370297444, server=p0419.mtv.cloudera.com,32877,1397370265023} > 2014-04-12 23:24:57,444 INFO [AM.ZK.Worker-pool2-t12] master.RegionStates(457): Offlined 63cdcba1fc55ae6463463ae16f4e454e from p0419.mtv.cloudera.com,32877,1397370265023 > 2014-04-12 23:24:57,452 DEBUG [AM.ZK.Worker-pool2-t14] zookeeper.ZKAssign(480): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Deleted unassigned node d383980be98665b638fd56bfac97a351 in expected state RS_ZK_REGION_CLOSED > 2014-04-12 23:24:57,452 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/region-in-transition/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:57,452 INFO [AM.ZK.Worker-pool2-t14] master.RegionStates(316): Transitioned {d383980be98665b638fd56bfac97a351 state=PENDING_CLOSE, ts=1397370297320, server=p0419.mtv.cloudera.com,41017,1397370264982} to {d383980be98665b638fd56bfac97a351 state=OFFLINE, ts=1397370297452, server=p0419.mtv.cloudera.com,41017,1397370264982} > 2014-04-12 23:24:57,452 INFO [AM.ZK.Worker-pool2-t14] master.RegionStates(457): Offlined d383980be98665b638fd56bfac97a351 from p0419.mtv.cloudera.com,41017,1397370264982 > 2014-04-12 23:24:57,482 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DisableTableHandler$BulkDisabler(230): Disable waiting until done; 299846 ms remaining; [] > 2014-04-12 23:24:57,493 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DisableTableHandler(190): Disabled table is done=true > 2014-04-12 23:24:57,502 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] lock.ZKInterProcessLockBase(328): Released /hbase/table-lock/testQuarantineMissingHFile/write-master:330010000000001 > 2014-04-12 23:24:57,504 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=catalogtracker-on-hconnection-0x1ae9e1aa connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:57,505 DEBUG [Thread-587] catalog.CatalogTracker(193): Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@6c7f76bb > 2014-04-12 23:24:57,519 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:57,519 DEBUG [Thread-587] zookeeper.ZKUtil(428): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Set watcher on existing znode=/hbase/meta-region-server > 2014-04-12 23:24:57,520 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): catalogtracker-on-hconnection-0x1ae9e1aa-0x14559c215740044 connected > 2014-04-12 23:24:57,525 DEBUG [Thread-587] catalog.CatalogTracker(209): Stopping catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@6c7f76bb > 2014-04-12 23:24:57,536 INFO [Thread-587] client.HBaseAdmin(964): Disabled testQuarantineMissingHFile > 2014-04-12 23:24:57,540 INFO [Thread-587] util.HBaseFsck(3774): Checking all hfiles for corruption > 2014-04-12 23:24:57,602 INFO [IPC Server handler 7 on 50919] blockmanagement.BlockManager(1053): BLOCK* addToInvalidates: blk_1073741872_1048 127.0.0.1:49422 127.0.0.1:53997 127.0.0.1:33353 > 2014-04-12 23:24:57,638 WARN [IPC Server handler 4 on 50919] security.UserGroupInformation(1551): PriviledgedActionException as:jenkins (auth:SIMPLE) cause:java.io.FileNotFoundException: File does not exist: /user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/fam/57a07eaac97e4acd8dc04e08d1950adc > 2014-04-12 23:24:57,640 WARN [pool-115-thread-1] hbck.HFileCorruptionChecker(111): HFile hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/fam/57a07eaac97e4acd8dc04e08d1950adc was missing. Likely removed due to compaction/split? > 2014-04-12 23:24:57,652 INFO [IPC Server handler 2 on 50919] blockmanagement.BlockManager(1053): BLOCK* addToInvalidates: blk_1073741874_1050 127.0.0.1:33353 127.0.0.1:53997 127.0.0.1:49422 > 2014-04-12 23:24:57,679 WARN [IPC Server handler 3 on 50919] security.UserGroupInformation(1551): PriviledgedActionException as:jenkins (auth:SIMPLE) cause:java.io.FileNotFoundException: File does not exist: /user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/fam/9dd79f30f29e4cfeaa46f6e20b32e078 > 2014-04-12 23:24:57,680 WARN [pool-115-thread-3] hbck.HFileCorruptionChecker(111): HFile hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/fam/9dd79f30f29e4cfeaa46f6e20b32e078 was missing. Likely removed due to compaction/split? > 2014-04-12 23:24:57,682 INFO [Thread-587] util.HBaseFsck(375): Loading regioninfos HDFS > 2014-04-12 23:24:57,682 INFO [Thread-587] util.HBaseFsck(608): Loading HBase regioninfo from HDFS... > 2014-04-12 23:24:57,691 DEBUG [Thread-587] util.HBaseFsck(1334): Loading region dirs from hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile > 2014-04-12 23:24:57,691 DEBUG [Thread-587] util.HBaseFsck(1334): Loading region dirs from hdfs://localhost:50919/user/jenkins/hbase/data/hbase/meta > 2014-04-12 23:24:57,693 DEBUG [pool-115-thread-2] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:57,693 DEBUG [pool-115-thread-1] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/hbase/meta/1588230740 > 2014-04-12 23:24:57,696 DEBUG [pool-115-thread-2] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:57,699 DEBUG [pool-115-thread-2] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:57,701 DEBUG [pool-115-thread-2] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:57,714 DEBUG [pool-115-thread-4] util.HBaseFsck(762): HRegionInfo read: {ENCODED => 1588230740, NAME => 'hbase:meta,,1', STARTKEY => '', ENDKEY => ''} > 2014-04-12 23:24:57,721 DEBUG [pool-115-thread-3] util.HBaseFsck(762): HRegionInfo read: {ENCODED => 63cdcba1fc55ae6463463ae16f4e454e, NAME => 'testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.', STARTKEY => '', ENDKEY => 'A'} > 2014-04-12 23:24:57,755 DEBUG [pool-115-thread-6] util.HBaseFsck(762): HRegionInfo read: {ENCODED => d383980be98665b638fd56bfac97a351, NAME => 'testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.', STARTKEY => 'B', ENDKEY => 'C'} > 2014-04-12 23:24:57,755 DEBUG [pool-115-thread-1] util.HBaseFsck(762): HRegionInfo read: {ENCODED => f9c185520bca999a753ee3ce0a244f6d, NAME => 'testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.', STARTKEY => 'C', ENDKEY => ''} > 2014-04-12 23:24:57,756 DEBUG [pool-115-thread-5] util.HBaseFsck(762): HRegionInfo read: {ENCODED => a8a68d998d21b00499aca60887ae5aef, NAME => 'testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.', STARTKEY => 'A', ENDKEY => 'B'} > 2014-04-12 23:24:57,782 INFO [Thread-587] util.HBaseFsck(1107): Checking HBase region split map from HDFS data... > 2014-04-12 23:24:57,782 INFO [Thread-587] util.HBaseFsck(617): No integrity errors. We are done with this phase. Glorious. > 2014-04-12 23:24:57,835 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/balancer > 2014-04-12 23:24:57,836 INFO [RpcServer.handler=0,port=33001] master.HMaster(1550): Client=jenkins//172.29.122.11 set balanceSwitch=false > 2014-04-12 23:24:57,840 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=hbase Fsck connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:57,869 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): hbase Fsck, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:57,870 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): hbase Fsck-0x14559c215740045 connected > 2014-04-12 23:24:57,902 INFO [Thread-587] util.HBaseFsck(431): Loading regionsinfo from the hbase:meta table > 2014-04-12 23:24:57,912 INFO [Thread-587] util.HBaseFsck(2521): getHTableDescriptors == tableNames => [] > 2014-04-12 23:24:57,922 DEBUG [Thread-587] util.HBaseFsck(1334): Loading region dirs from hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile > 2014-04-12 23:24:57,922 DEBUG [Thread-587] util.HBaseFsck(1334): Loading region dirs from hdfs://localhost:50919/user/jenkins/hbase/data/hbase/meta > 2014-04-12 23:24:57,923 DEBUG [pool-115-thread-10] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/hbase/meta/1588230740 > 2014-04-12 23:24:57,924 DEBUG [pool-115-thread-9] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:57,926 DEBUG [pool-115-thread-9] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:57,929 DEBUG [pool-115-thread-9] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:57,931 DEBUG [pool-115-thread-9] util.HBaseFsck$WorkItemHdfsDir(3211): Loading region info from hdfs:hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:57,936 DEBUG [pool-115-thread-4] util.HBaseFsck(762): HRegionInfo read: {ENCODED => 1588230740, NAME => 'hbase:meta,,1', STARTKEY => '', ENDKEY => ''} > 2014-04-12 23:24:57,937 DEBUG [pool-115-thread-1] util.HBaseFsck(762): HRegionInfo read: {ENCODED => d383980be98665b638fd56bfac97a351, NAME => 'testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.', STARTKEY => 'B', ENDKEY => 'C'} > 2014-04-12 23:24:57,977 DEBUG [pool-115-thread-6] util.HBaseFsck(762): HRegionInfo read: {ENCODED => a8a68d998d21b00499aca60887ae5aef, NAME => 'testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.', STARTKEY => 'A', ENDKEY => 'B'} > 2014-04-12 23:24:57,977 DEBUG [pool-115-thread-5] util.HBaseFsck(762): HRegionInfo read: {ENCODED => f9c185520bca999a753ee3ce0a244f6d, NAME => 'testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.', STARTKEY => 'C', ENDKEY => ''} > 2014-04-12 23:24:57,978 DEBUG [pool-115-thread-3] util.HBaseFsck(762): HRegionInfo read: {ENCODED => 63cdcba1fc55ae6463463ae16f4e454e, NAME => 'testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.', STARTKEY => '', ENDKEY => 'A'} > 2014-04-12 23:24:58,004 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=hbase Fsck connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:58,036 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): hbase Fsck, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:58,037 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): hbase Fsck-0x14559c215740046 connected > 2014-04-12 23:24:58,069 INFO [Thread-587] util.HBaseFsck(1650): Region { meta => testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e., hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e, deployed => } is in META, and in a disabled tabled that is not deployed > 2014-04-12 23:24:58,069 INFO [Thread-587] util.HBaseFsck(1650): Region { meta => testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef., hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef, deployed => } is in META, and in a disabled tabled that is not deployed > 2014-04-12 23:24:58,069 INFO [Thread-587] util.HBaseFsck(1650): Region { meta => testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351., hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351, deployed => } is in META, and in a disabled tabled that is not deployed > 2014-04-12 23:24:58,069 INFO [Thread-587] util.HBaseFsck(1650): Region { meta => testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d., hdfs => hdfs://localhost:50919/user/jenkins/hbase/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d, deployed => } is in META, and in a disabled tabled that is not deployed > 2014-04-12 23:24:58,070 DEBUG [Thread-587] util.HBaseFsck(1804): There are 5 region info entries > 2014-04-12 23:24:58,110 DEBUG [pool-1-thread-1-EventThread] zookeeper.ZooKeeperWatcher(310): master:33001-0x14559c215740000, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/balancer > 2014-04-12 23:24:58,111 INFO [RpcServer.handler=0,port=33001] master.HMaster(1550): Client=jenkins//172.29.122.11 set balanceSwitch=true > 2014-04-12 23:24:58,152 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=hbase Fsck connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:58,177 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): hbase Fsck, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:58,179 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): hbase Fsck-0x14559c215740047 connected > 2014-04-12 23:24:58,182 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=catalogtracker-on-hconnection-0x1ae9e1aa connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:58,182 DEBUG [Thread-587] catalog.CatalogTracker(193): Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@73b62d67 > 2014-04-12 23:24:58,219 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:58,219 DEBUG [Thread-587] zookeeper.ZKUtil(428): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Set watcher on existing znode=/hbase/meta-region-server > 2014-04-12 23:24:58,220 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): catalogtracker-on-hconnection-0x1ae9e1aa-0x14559c215740048 connected > 2014-04-12 23:24:58,226 DEBUG [Thread-587] catalog.CatalogTracker(209): Stopping catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@73b62d67 > 2014-04-12 23:24:58,279 INFO [Thread-587] zookeeper.RecoverableZooKeeper(120): Process identifier=catalogtracker-on-hconnection-0x1ae9e1aa connecting to ZooKeeper ensemble=localhost:53570 > 2014-04-12 23:24:58,279 DEBUG [Thread-587] catalog.CatalogTracker(193): Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@490d9812 > 2014-04-12 23:24:58,302 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null > 2014-04-12 23:24:58,303 DEBUG [Thread-587] zookeeper.ZKUtil(428): catalogtracker-on-hconnection-0x1ae9e1aa, quorum=localhost:53570, baseZNode=/hbase Set watcher on existing znode=/hbase/meta-region-server > 2014-04-12 23:24:58,303 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(387): catalogtracker-on-hconnection-0x1ae9e1aa-0x14559c215740049 connected > 2014-04-12 23:24:58,309 DEBUG [Thread-587] catalog.CatalogTracker(209): Stopping catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@490d9812 > 2014-04-12 23:24:58,354 INFO [RpcServer.handler=0,port=33001] master.HMaster(1817): Client=jenkins//172.29.122.11 delete testQuarantineMissingHFile > 2014-04-12 23:24:58,420 DEBUG [RpcServer.handler=0,port=33001] lock.ZKInterProcessLockBase(226): Acquired a lock for /hbase/table-lock/testQuarantineMissingHFile/write-master:330010000000002 > 2014-04-12 23:24:58,432 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.TableEventHandler(123): Handling table operation C_M_DELETE_TABLE on table testQuarantineMissingHFile > 2014-04-12 23:24:58,438 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(93): Deleting regions from META > 2014-04-12 23:24:58,449 INFO [MASTER_TABLE_OPERATIONS-p0419:33001-0] catalog.MetaEditor(495): Deleted [{ENCODED => 63cdcba1fc55ae6463463ae16f4e454e, NAME => 'testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e.', STARTKEY => '', ENDKEY => 'A'}, {ENCODED => a8a68d998d21b00499aca60887ae5aef, NAME => 'testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef.', STARTKEY => 'A', ENDKEY => 'B'}, {ENCODED => d383980be98665b638fd56bfac97a351, NAME => 'testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351.', STARTKEY => 'B', ENDKEY => 'C'}, {ENCODED => f9c185520bca999a753ee3ce0a244f6d, NAME => 'testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d.', STARTKEY => 'C', ENDKEY => ''}] > 2014-04-12 23:24:58,510 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(104): Archiving region testQuarantineMissingHFile,,1397370294808.63cdcba1fc55ae6463463ae16f4e454e. from FS > 2014-04-12 23:24:58,511 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(93): ARCHIVING hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:58,515 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(134): Archiving [class org.apache.hadoop.hbase.backup.HFileArchiver$FileablePath, file:hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e/fam] > 2014-04-12 23:24:58,635 INFO [IPC Server handler 2 on 50919] blockmanagement.BlockManager(1053): BLOCK* addToInvalidates: blk_1073741869_1045 127.0.0.1:49422 127.0.0.1:33353 127.0.0.1:53997 > 2014-04-12 23:24:58,636 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(453): Deleted all region files in: hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/63cdcba1fc55ae6463463ae16f4e454e > 2014-04-12 23:24:58,636 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(104): Archiving region testQuarantineMissingHFile,A,1397370294808.a8a68d998d21b00499aca60887ae5aef. from FS > 2014-04-12 23:24:58,636 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(93): ARCHIVING hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:58,641 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(134): Archiving [class org.apache.hadoop.hbase.backup.HFileArchiver$FileablePath, file:hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef/fam] > 2014-04-12 23:24:58,802 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(438): Finished archiving from class org.apache.hadoop.hbase.backup.HFileArchiver$FileablePath, file:hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef/fam/0ce0a00435f64a02856bfe0fb779093b, to hdfs://localhost:50919/user/jenkins/hbase/archive/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef/fam/0ce0a00435f64a02856bfe0fb779093b > 2014-04-12 23:24:58,835 INFO [IPC Server handler 7 on 50919] blockmanagement.BlockManager(1053): BLOCK* addToInvalidates: blk_1073741871_1047 127.0.0.1:33353 127.0.0.1:53997 127.0.0.1:49422 > 2014-04-12 23:24:58,836 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(453): Deleted all region files in: hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/a8a68d998d21b00499aca60887ae5aef > 2014-04-12 23:24:58,836 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(104): Archiving region testQuarantineMissingHFile,B,1397370294808.d383980be98665b638fd56bfac97a351. from FS > 2014-04-12 23:24:58,836 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(93): ARCHIVING hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:58,840 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(134): Archiving [class org.apache.hadoop.hbase.backup.HFileArchiver$FileablePath, file:hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351/fam] > 2014-04-12 23:24:58,860 INFO [IPC Server handler 7 on 50919] blockmanagement.BlockManager(1053): BLOCK* addToInvalidates: blk_1073741868_1044 127.0.0.1:53997 127.0.0.1:49422 127.0.0.1:33353 > 2014-04-12 23:24:58,861 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(453): Deleted all region files in: hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/d383980be98665b638fd56bfac97a351 > 2014-04-12 23:24:58,861 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(104): Archiving region testQuarantineMissingHFile,C,1397370294808.f9c185520bca999a753ee3ce0a244f6d. from FS > 2014-04-12 23:24:58,861 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(93): ARCHIVING hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:58,865 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(134): Archiving [class org.apache.hadoop.hbase.backup.HFileArchiver$FileablePath, file:hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d/fam] > 2014-04-12 23:24:58,893 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(438): Finished archiving from class org.apache.hadoop.hbase.backup.HFileArchiver$FileablePath, file:hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d/fam/404e9e4c06b54305a0831dc4749d9a5f, to hdfs://localhost:50919/user/jenkins/hbase/archive/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d/fam/404e9e4c06b54305a0831dc4749d9a5f > 2014-04-12 23:24:58,902 INFO [IPC Server handler 8 on 50919] blockmanagement.BlockManager(1053): BLOCK* addToInvalidates: blk_1073741870_1046 127.0.0.1:33353 127.0.0.1:53997 127.0.0.1:49422 > 2014-04-12 23:24:58,902 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] backup.HFileArchiver(453): Deleted all region files in: hdfs://localhost:50919/user/jenkins/hbase/.tmp/data/default/testQuarantineMissingHFile/f9c185520bca999a753ee3ce0a244f6d > 2014-04-12 23:24:58,910 INFO [IPC Server handler 5 on 50919] blockmanagement.BlockManager(1053): BLOCK* addToInvalidates: blk_1073741867_1043 127.0.0.1:33353 127.0.0.1:53997 127.0.0.1:49422 > 2014-04-12 23:24:58,910 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(114): Table 'testQuarantineMissingHFile' archived! > 2014-04-12 23:24:58,911 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(117): Removing 'testQuarantineMissingHFile' descriptor. > 2014-04-12 23:24:58,912 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(121): Removing 'testQuarantineMissingHFile' from region states. > 2014-04-12 23:24:58,912 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] handler.DeleteTableHandler(125): Marking 'testQuarantineMissingHFile' as deleted. > 2014-04-12 23:24:58,927 DEBUG [MASTER_TABLE_OPERATIONS-p0419:33001-0] lock.ZKInterProcessLockBase(328): Released /hbase/table-lock/testQuarantineMissingHFile/write-master:330010000000002 > 2014-04-12 23:24:59,068 INFO [Thread-587] client.HBaseAdmin(696): Deleted testQuarantineMissingHFile > 2014-04-12 23:24:59,115 INFO [pool-1-thread-1] hbase.ResourceChecker(171): after: util.TestHBaseFsck#testQuarantineMissingHFile Thread=420 (was 410) > Potentially hanging thread: Thread-587-SendThread(localhost:53570) > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338) > org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1075) > Potentially hanging thread: pool-115-thread-1 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-6 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: DataXceiver for client DFSClient_NONMAPREDUCE_-1456019779_8 at /127.0.0.1:34032 [Waiting for operation #5] > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) > org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) > java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > java.io.BufferedInputStream.read(BufferedInputStream.java:254) > java.io.DataInputStream.readShort(DataInputStream.java:312) > org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.readOp(Receiver.java:55) > org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:206) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-4 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-3 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-5 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: Thread-587-EventThread > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) > org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494) > Potentially hanging thread: pool-115-thread-9 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: DataXceiver for client DFSClient_NONMAPREDUCE_-1456019779_8 at /127.0.0.1:34026 [Waiting for operation #7] > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) > org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) > java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > java.io.BufferedInputStream.read(BufferedInputStream.java:254) > java.io.DataInputStream.readShort(DataInputStream.java:312) > org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.readOp(Receiver.java:55) > org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:206) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: DataXceiver for client DFSClient_NONMAPREDUCE_-1456019779_8 at /127.0.0.1:33883 [Waiting for operation #12] > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) > org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) > java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > java.io.BufferedInputStream.read(BufferedInputStream.java:254) > java.io.DataInputStream.readShort(DataInputStream.java:312) > org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.readOp(Receiver.java:55) > org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:206) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-8 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-10 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: DataXceiver for client DFSClient_NONMAPREDUCE_-1456019779_8 at /127.0.0.1:36692 [Waiting for operation #7] > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) > org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) > java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > java.io.BufferedInputStream.read(BufferedInputStream.java:254) > java.io.DataInputStream.readShort(DataInputStream.java:312) > org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.readOp(Receiver.java:55) > org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:206) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: DataXceiver for client DFSClient_NONMAPREDUCE_-1456019779_8 at /127.0.0.1:44587 [Waiting for operation #12] > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) > org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) > java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > java.io.BufferedInputStream.read(BufferedInputStream.java:254) > java.io.DataInputStream.readShort(DataInputStream.java:312) > org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.readOp(Receiver.java:55) > org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:206) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: DataXceiver for client DFSClient_NONMAPREDUCE_-1456019779_8 at /127.0.0.1:36707 [Waiting for operation #6] > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) > org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) > java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > java.io.BufferedInputStream.read(BufferedInputStream.java:254) > java.io.DataInputStream.readShort(DataInputStream.java:312) > org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.readOp(Receiver.java:55) > org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:206) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-2 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: DataXceiver for client DFSClient_NONMAPREDUCE_-1456019779_8 at /127.0.0.1:44585 [Waiting for operation #14] > sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) > org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) > org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) > java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > java.io.BufferedInputStream.read(BufferedInputStream.java:254) > java.io.DataInputStream.readShort(DataInputStream.java:312) > org.apache.hadoop.hdfs.protocol.datatransfer.Receiver.readOp(Receiver.java:55) > org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:206) > java.lang.Thread.run(Thread.java:724) > Potentially hanging thread: pool-115-thread-7 > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079) > java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > java.lang.Thread.run(Thread.java:724) > - Thread LEAK? -, OpenFileDescriptor=692 (was 691) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=32768 (was 32768), SystemLoadAverage=453 (was 422) - SystemLoadAverage LEAK? -, ProcessCount=485 (was 485), AvailableMemoryMB=3026 (was 3139), ConnectionCount=5 (was 5) > 2014-04-12 23:28:53,025 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(310): hbase Fsck-0x14559c215740047, quorum=localhost:53570, baseZNode=/hbase Received ZooKeeper Event, type=None, state=Disconnected, path=null > 2014-04-12 23:28:53,025 DEBUG [Thread-587-EventThread] zookeeper.ZooKeeperWatcher(392): hbase Fsck-0x14559c215740047, quorum=localhost:53570, baseZNode=/hbase Received Disconnected from ZooKeeper, ignoring > {code} -- This message was sent by Atlassian JIRA (v6.2#6252)