You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "stack (JIRA)" <ji...@apache.org> on 2014/08/22 23:52:13 UTC
[jira] [Updated] (HBASE-10977)
TestHBaseFsck.testQuarantineMissingHFile fails missing files test
[ https://issues.apache.org/jira/browse/HBASE-10977?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack updated HBASE-10977:
--------------------------
Affects Version/s: 0.94.15
> TestHBaseFsck.testQuarantineMissingHFile fails missing files test
> -----------------------------------------------------------------
>
> Key: HBASE-10977
> URL: https://issues.apache.org/jira/browse/HBASE-10977
> Project: HBase
> Issue Type: Bug
> Affects Versions: 0.94.15
> 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)