hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Srikanth Srungarapu (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HBASE-13294) Fix the critical ancient loopholes in security testing infrastructure.
Date Sat, 21 Mar 2015 03:18:41 GMT

    [ https://issues.apache.org/jira/browse/HBASE-13294?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14372477#comment-14372477 ] 

Srikanth Srungarapu commented on HBASE-13294:
---------------------------------------------

Looking at the cause for test failures in jenkins, there seems to be a problem spinning up cluster. The test is running well on local box.  Re-attaching the patch for another try.
{code}
Failed

org.apache.hadoop.hbase.security.access.TestAccessController.org.apache.hadoop.hbase.security.access.TestAccessController
Failing for the past 1 build (Since Failed#13344 )
Took 6 ms.
Error Message

Shutting down

Stacktrace

java.io.IOException: Shutting down
	at org.apache.hadoop.hbase.util.JVMClusterUtil.startup(JVMClusterUtil.java:225)
	at org.apache.hadoop.hbase.LocalHBaseCluster.startup(LocalHBaseCluster.java:437)
	at org.apache.hadoop.hbase.MiniHBaseCluster.init(MiniHBaseCluster.java:224)
	at org.apache.hadoop.hbase.MiniHBaseCluster.<init>(MiniHBaseCluster.java:93)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:1008)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:968)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:842)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:836)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:780)
	at org.apache.hadoop.hbase.security.access.TestAccessController.setupBeforeClass(TestAccessController.java:191)

Standard Output

Formatting using clusterid: testClusterID
Process Thread Dump: Thread dump because: Master not initialized after 200000ms seconds
70 active threads
Thread 287 (IPC Parameter Sending Thread #1):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 66
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
    java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359)
    java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942)
    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:744)
Thread 263 (HBase-Metrics2-1):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 79
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
    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:744)
Thread 189 (AsyncRpcChannel-timer-pool1-t1):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1986
  Stack:
    java.lang.Thread.sleep(Native Method)
    io.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:461)
    io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:360)
    java.lang.Thread.run(Thread.java:744)
Thread 190 (AsyncRpcChannel-pool2-t1):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    java.lang.Thread.run(Thread.java:744)
Thread 251 (snapshot-hfile-cleaner-cache-refresher):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    java.lang.Object.wait(Native Method)
    java.util.TimerThread.mainLoop(Timer.java:552)
    java.util.TimerThread.run(Timer.java:505)
Thread 250 (snapshot-log-cleaner-cache-refresher):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    java.lang.Object.wait(Native Method)
    java.util.TimerThread.mainLoop(Timer.java:552)
    java.util.TimerThread.run(Timer.java:505)
Thread 248 (proserpina:38530.activeMasterManager-EventThread):
  State: WAITING
  Blocked count: 0
  Waited count: 3
  Waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@707a9713
  Stack:
    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)
Thread 247 (proserpina:38530.activeMasterManager-SendThread(localhost:55239)):
  State: RUNNABLE
  Blocked count: 2
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:349)
    org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
Thread 155 (org.apache.hadoop.hdfs.PeerCache@37f28e66):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 67
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.PeerCache.run(PeerCache.java:244)
    org.apache.hadoop.hdfs.PeerCache.access$000(PeerCache.java:41)
    org.apache.hadoop.hdfs.PeerCache$1.run(PeerCache.java:119)
    java.lang.Thread.run(Thread.java:744)
Thread 140 (Thread-102):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hbase.master.HMaster$InitializationMonitor.run(HMaster.java:197)
    java.lang.Thread.run(Thread.java:744)
Thread 93 (ProcessThread(sid:0 cport:-1):):
  State: WAITING
  Blocked count: 0
  Waited count: 158
  Waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@3c0bc4b5
  Stack:
    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.server.PrepRequestProcessor.run(PrepRequestProcessor.java:120)
Thread 92 (SyncThread:0):
  State: WAITING
  Blocked count: 0
  Waited count: 128
  Waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@289f65df
  Stack:
    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.server.SyncRequestProcessor.run(SyncRequestProcessor.java:127)
Thread 91 (SessionTracker):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 103
  Stack:
    java.lang.Object.wait(Native Method)
    org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:146)
Thread 90 (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:55239):
  State: RUNNABLE
  Blocked count: 3
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:178)
    java.lang.Thread.run(Thread.java:744)
Thread 87 (refreshUsed-/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data2/current/BP-27234177-67.195.81.189-1426903856367):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.fs.DU$DURefreshThread.run(DU.java:115)
    java.lang.Thread.run(Thread.java:744)
Thread 86 (refreshUsed-/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data1/current/BP-27234177-67.195.81.189-1426903856367):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.fs.DU$DURefreshThread.run(DU.java:115)
    java.lang.Thread.run(Thread.java:744)
Thread 80 (java.util.concurrent.ThreadPoolExecutor$Worker@4b35baa7[State = -1, empty queue]):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
    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:744)
Thread 77 (Thread-62):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 41
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.datanode.DataBlockScanner.run(DataBlockScanner.java:78)
    java.lang.Thread.run(Thread.java:744)
Thread 71 (IPC Client (1743776012) connection to localhost/127.0.0.1:42912 from jenkins):
  State: TIMED_WAITING
  Blocked count: 83
  Waited count: 83
  Stack:
    java.lang.Object.wait(Native Method)
    org.apache.hadoop.ipc.Client$Connection.waitForWork(Client.java:904)
    org.apache.hadoop.ipc.Client$Connection.run(Client.java:949)
Thread 70 (IPC Server handler 9 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 252
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 69 (IPC Server handler 8 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 247
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 68 (IPC Server handler 7 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 214
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 67 (IPC Server handler 6 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 246
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 66 (IPC Server handler 5 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 256
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 65 (IPC Server handler 4 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 229
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 64 (IPC Server handler 3 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 255
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 63 (IPC Server handler 2 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 242
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 62 (IPC Server handler 1 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 236
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 61 (IPC Server handler 0 on 34438):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 238
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 56 (IPC Server listener on 34438):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:102)
    org.apache.hadoop.ipc.Server$Listener.run(Server.java:668)
Thread 59 (IPC Server Responder):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    org.apache.hadoop.ipc.Server$Responder.doRunLoop(Server.java:835)
    org.apache.hadoop.ipc.Server$Responder.run(Server.java:818)
Thread 51 (org.apache.hadoop.hdfs.server.datanode.DataXceiverServer@599556aa):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
    sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
    sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241)
    sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:100)
    org.apache.hadoop.hdfs.net.TcpPeerServer.accept(TcpPeerServer.java:134)
    org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:137)
    java.lang.Thread.run(Thread.java:744)
Thread 60 (DataNode: [[[DISK]file:/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data1/, [DISK]file:/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data2/]]  heartbeating to localhost/127.0.0.1:42912):
  State: TIMED_WAITING
  Blocked count: 128
  Waited count: 245
  Stack:
    java.lang.Object.wait(Native Method)
    org.apache.hadoop.hdfs.server.datanode.BPServiceActor.offerService(BPServiceActor.java:720)
    org.apache.hadoop.hdfs.server.datanode.BPServiceActor.run(BPServiceActor.java:834)
    java.lang.Thread.run(Thread.java:744)
Thread 58 (IPC Server idle connection scanner for port 34438):
  State: TIMED_WAITING
  Blocked count: 1
  Waited count: 22
  Stack:
    java.lang.Object.wait(Native Method)
    java.util.TimerThread.mainLoop(Timer.java:552)
    java.util.TimerThread.run(Timer.java:505)
Thread 57 (Socket Reader #1 for port 34438):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:102)
    org.apache.hadoop.ipc.Server$Listener$Reader.doRunLoop(Server.java:616)
    org.apache.hadoop.ipc.Server$Listener$Reader.run(Server.java:595)
Thread 55 (org.apache.hadoop.util.JvmPauseMonitor$Monitor@3c65666c):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 411
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.util.JvmPauseMonitor$Monitor.run(JvmPauseMonitor.java:180)
    java.lang.Thread.run(Thread.java:744)
Thread 54 (Timer-1):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 7
  Stack:
    java.lang.Object.wait(Native Method)
    java.util.TimerThread.mainLoop(Timer.java:552)
    java.util.TimerThread.run(Timer.java:505)
Thread 53 (743692891@qtp-424890708-1 - Acceptor0 HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:37974):
  State: RUNNABLE
  Blocked count: 1
  Waited count: 1
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:498)
    org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:192)
    org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124)
    org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:708)
    org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Thread 52 (1114171041@qtp-424890708-0):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 4
  Stack:
    java.lang.Object.wait(Native Method)
    org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
Thread 46 (CacheReplicationMonitor(1637185326)):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 7
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2176)
    org.apache.hadoop.hdfs.server.blockmanagement.CacheReplicationMonitor.run(CacheReplicationMonitor.java:181)
Thread 45 (org.apache.hadoop.hdfs.server.namenode.FSNamesystem$NameNodeEditLogRoller@7cc8b288):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.namenode.FSNamesystem$NameNodeEditLogRoller.run(FSNamesystem.java:4726)
    java.lang.Thread.run(Thread.java:744)
Thread 44 (org.apache.hadoop.hdfs.server.namenode.FSNamesystem$NameNodeResourceMonitor@1bbbfb71):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 42
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.namenode.FSNamesystem$NameNodeResourceMonitor.run(FSNamesystem.java:4687)
    java.lang.Thread.run(Thread.java:744)
Thread 43 (org.apache.hadoop.hdfs.server.namenode.LeaseManager$Monitor@57b3fe3c):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 104
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.namenode.LeaseManager$Monitor.run(LeaseManager.java:392)
    java.lang.Thread.run(Thread.java:744)
Thread 42 (IPC Server handler 9 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 239
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 41 (IPC Server handler 8 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 213
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 40 (IPC Server handler 7 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 260
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 39 (IPC Server handler 6 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 213
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 38 (IPC Server handler 5 on 42912):
  State: TIMED_WAITING
  Blocked count: 1
  Waited count: 214
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 37 (IPC Server handler 4 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 213
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 36 (IPC Server handler 3 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 213
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 35 (IPC Server handler 2 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 214
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 34 (IPC Server handler 1 on 42912):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 214
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 33 (IPC Server handler 0 on 42912):
  State: TIMED_WAITING
  Blocked count: 12
  Waited count: 243
  Stack:
    sun.misc.Unsafe.park(Native Method)
    java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    org.apache.hadoop.ipc.CallQueueManager.take(CallQueueManager.java:109)
    org.apache.hadoop.ipc.Server$Handler.run(Server.java:1985)
Thread 23 (IPC Server listener on 42912):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:102)
    org.apache.hadoop.ipc.Server$Listener.run(Server.java:668)
Thread 26 (IPC Server Responder):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    org.apache.hadoop.ipc.Server$Responder.doRunLoop(Server.java:835)
    org.apache.hadoop.ipc.Server$Responder.run(Server.java:818)
Thread 21 (org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor@6b7dcfcd):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 70
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor.run(BlockManager.java:3397)
    java.lang.Thread.run(Thread.java:744)
Thread 22 (org.apache.hadoop.hdfs.server.blockmanagement.HeartbeatManager$Monitor@10d5d2dd):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 42
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.blockmanagement.HeartbeatManager$Monitor.run(HeartbeatManager.java:319)
    java.lang.Thread.run(Thread.java:744)
Thread 32 (org.apache.hadoop.hdfs.server.blockmanagement.DecommissionManager$Monitor@10c8414a):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 70
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.blockmanagement.DecommissionManager$Monitor.run(DecommissionManager.java:76)
    java.lang.Thread.run(Thread.java:744)
Thread 31 (org.apache.hadoop.hdfs.server.blockmanagement.PendingReplicationBlocks$PendingReplicationMonitor@4ba6ee31):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 1
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.hdfs.server.blockmanagement.PendingReplicationBlocks$PendingReplicationMonitor.run(PendingReplicationBlocks.java:221)
    java.lang.Thread.run(Thread.java:744)
Thread 27 (org.apache.hadoop.util.JvmPauseMonitor$Monitor@3301378d):
  State: TIMED_WAITING
  Blocked count: 1
  Waited count: 412
  Stack:
    java.lang.Thread.sleep(Native Method)
    org.apache.hadoop.util.JvmPauseMonitor$Monitor.run(JvmPauseMonitor.java:180)
    java.lang.Thread.run(Thread.java:744)
Thread 25 (IPC Server idle connection scanner for port 42912):
  State: TIMED_WAITING
  Blocked count: 1
  Waited count: 22
  Stack:
    java.lang.Object.wait(Native Method)
    java.util.TimerThread.mainLoop(Timer.java:552)
    java.util.TimerThread.run(Timer.java:505)
Thread 24 (Socket Reader #1 for port 42912):
  State: RUNNABLE
  Blocked count: 1
  Waited count: 0
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:102)
    org.apache.hadoop.ipc.Server$Listener$Reader.doRunLoop(Server.java:616)
    org.apache.hadoop.ipc.Server$Listener$Reader.run(Server.java:595)
Thread 20 (Timer-0):
  State: TIMED_WAITING
  Blocked count: 1
  Waited count: 8
  Stack:
    java.lang.Object.wait(Native Method)
    java.util.TimerThread.mainLoop(Timer.java:552)
    java.util.TimerThread.run(Timer.java:505)
Thread 19 (108697051@qtp-1424309400-1 - Acceptor0 HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:46463):
  State: RUNNABLE
  Blocked count: 1
  Waited count: 1
  Stack:
    sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
    sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
    sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
    org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:498)
    org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:192)
    org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124)
    org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:708)
    org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Thread 18 (2111490614@qtp-1424309400-0):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 4
  Stack:
    java.lang.Object.wait(Native Method)
    org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
Thread 16 (Timer for 'NameNode' metrics system):
  State: TIMED_WAITING
  Blocked count: 0
  Waited count: 21
  Stack:
    java.lang.Object.wait(Native Method)
    java.util.TimerThread.mainLoop(Timer.java:552)
    java.util.TimerThread.run(Timer.java:505)
Thread 4 (Signal Dispatcher):
  State: RUNNABLE
  Blocked count: 0
  Waited count: 0
  Stack:
Thread 3 (Finalizer):
  State: WAITING
  Blocked count: 34
  Waited count: 3
  Waiting on java.lang.ref.ReferenceQueue$Lock@7ce28a19
  Stack:
    java.lang.Object.wait(Native Method)
    java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)
Thread 2 (Reference Handler):
  State: WAITING
  Blocked count: 5
  Waited count: 4
  Waiting on java.lang.ref.Reference$Lock@7cd8af5c
  Stack:
    java.lang.Object.wait(Native Method)
    java.lang.Object.wait(Object.java:503)
    java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
Thread 1 (main):
  State: RUNNABLE
  Blocked count: 93
  Waited count: 506
  Stack:
    sun.management.ThreadImpl.getThreadInfo1(Native Method)
    sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:174)
    sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:139)
    org.apache.hadoop.util.ReflectionUtils.printThreadInfo(ReflectionUtils.java:165)
    sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    java.lang.reflect.Method.invoke(Method.java:606)
    org.apache.hadoop.hbase.util.Threads.printThreadInfo(Threads.java:302)
    org.apache.hadoop.hbase.util.JVMClusterUtil.startup(JVMClusterUtil.java:223)
    org.apache.hadoop.hbase.LocalHBaseCluster.startup(LocalHBaseCluster.java:437)
    org.apache.hadoop.hbase.MiniHBaseCluster.init(MiniHBaseCluster.java:224)
    org.apache.hadoop.hbase.MiniHBaseCluster.<init>(MiniHBaseCluster.java:93)
    org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:1008)
    org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:968)
    org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:842)
    org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:836)
    org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:780)
    org.apache.hadoop.hbase.security.access.TestAccessController.setupBeforeClass(TestAccessController.java:191)
    sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

Standard Error

2015-03-21 02:10:53,725 WARN  [main] util.NativeCodeLoader(62): Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-03-21 02:10:54,071 INFO  [main] hbase.HBaseTestingUtility(946): Starting up minicluster with 1 master(s) and 1 regionserver(s) and 1 datanode(s)
2015-03-21 02:10:54,156 INFO  [main] hbase.HBaseTestingUtility(436): Created new mini-cluster data directory: /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa, deleteOnExit=true
2015-03-21 02:10:54,158 INFO  [main] hbase.HBaseTestingUtility(676): Setting test.cache.data to /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/cache_data in system properties and HBase conf
2015-03-21 02:10:54,159 INFO  [main] hbase.HBaseTestingUtility(676): Setting hadoop.tmp.dir to /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/hadoop_tmp in system properties and HBase conf
2015-03-21 02:10:54,160 INFO  [main] hbase.HBaseTestingUtility(676): Setting hadoop.log.dir to /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/hadoop_logs in system properties and HBase conf
2015-03-21 02:10:54,161 INFO  [main] hbase.HBaseTestingUtility(676): Setting mapreduce.cluster.local.dir to /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/mapred_local in system properties and HBase conf
2015-03-21 02:10:54,162 INFO  [main] hbase.HBaseTestingUtility(676): Setting mapreduce.cluster.temp.dir to /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/mapred_temp in system properties and HBase conf
2015-03-21 02:10:54,167 INFO  [main] hbase.HBaseTestingUtility(667): read short circuit is OFF
2015-03-21 02:10:54,519 DEBUG [main] fs.HFileSystem(221): The file system is not a DistributedFileSystem. Skipping on block location reordering
2015-03-21 02:10:57,128 WARN  [main] impl.MetricsConfig(124): Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2015-03-21 02:10:57,371 INFO  [main] log.Slf4jLog(67): Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
2015-03-21 02:10:57,457 INFO  [main] log.Slf4jLog(67): jetty-6.1.26
2015-03-21 02:10:57,501 INFO  [main] log.Slf4jLog(67): Extract jar:file:/home/jenkins/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.5.1/hadoop-hdfs-2.5.1-tests.jar!/webapps/hdfs to /tmp/Jetty_localhost_46463_hdfs____.smgs9z/webapp
2015-03-21 02:10:57,923 WARN  [main] server.AuthenticationFilter(166): 'signature.secret' configuration not set, using a random value as secret
2015-03-21 02:10:57,997 INFO  [main] log.Slf4jLog(67): Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:46463
2015-03-21 02:10:59,540 INFO  [main] log.Slf4jLog(67): jetty-6.1.26
2015-03-21 02:10:59,562 INFO  [main] log.Slf4jLog(67): Extract jar:file:/home/jenkins/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.5.1/hadoop-hdfs-2.5.1-tests.jar!/webapps/datanode to /tmp/Jetty_localhost_37974_datanode____72s1cp/webapp
2015-03-21 02:10:59,764 INFO  [main] log.Slf4jLog(67): Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:37974
2015-03-21 02:11:01,200 INFO  [IPC Server handler 7 on 42912] blockmanagement.BlockManager(1753): BLOCK* processReport: from storage DS-20704df4-ae22-40c7-8dcd-b411672f6980 node DatanodeRegistration(127.0.0.1, datanodeUuid=bf0194c5-f830-4a3c-a9e4-a3e5516d3196, infoPort=37974, ipcPort=34438, storageInfo=lv=-55;cid=testClusterID;nsid=1057254946;c=0), blocks: 0, hasStaleStorages: true, processing time: 3 msecs
2015-03-21 02:11:01,200 INFO  [IPC Server handler 7 on 42912] blockmanagement.BlockManager(1753): BLOCK* processReport: from storage DS-a2d75141-06d2-4e32-a0f7-999efc9c94fc node DatanodeRegistration(127.0.0.1, datanodeUuid=bf0194c5-f830-4a3c-a9e4-a3e5516d3196, infoPort=37974, ipcPort=34438, storageInfo=lv=-55;cid=testClusterID;nsid=1057254946;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
2015-03-21 02:11:01,374 INFO  [main] zookeeper.MiniZooKeeperCluster(273): Started MiniZooKeeperCluster and ran successful 'stat' on client port=55239
2015-03-21 02:11:01,409 INFO  [main] fs.HFileSystem(252): Added intercepting call to namenode#getBlockLocations so can do block reordering using class class org.apache.hadoop.hbase.fs.HFileSystem$ReorderWALBlocks
2015-03-21 02:11:01,418 INFO  [main] fs.HFileSystem(252): Added intercepting call to namenode#getBlockLocations so can do block reordering using class class org.apache.hadoop.hbase.fs.HFileSystem$ReorderWALBlocks
2015-03-21 02:11:02,029 INFO  [IPC Server handler 8 on 42912] blockmanagement.BlockManager(2383): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:54374 is added to blk_1073741825_1001{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-20704df4-ae22-40c7-8dcd-b411672f6980:NORMAL|RBW]]} size 0
2015-03-21 02:11:02,074 INFO  [main] util.FSUtils(712): Created version file at hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6 with version=8
2015-03-21 02:11:02,354 INFO  [main] client.ConnectionUtils(105): master/proserpina.apache.org/67.195.81.189:0 server-side HConnection retries=350
2015-03-21 02:11:02,728 INFO  [main] ipc.SimpleRpcScheduler(128): Using deadline as user call queue, count=1
2015-03-21 02:11:02,829 INFO  [main] ipc.RpcServer$Listener(567): master/proserpina.apache.org/67.195.81.189:0: started 10 reader(s).
2015-03-21 02:11:02,870 INFO  [main] fs.HFileSystem(252): Added intercepting call to namenode#getBlockLocations so can do block reordering using class class org.apache.hadoop.hbase.fs.HFileSystem$ReorderWALBlocks
2015-03-21 02:11:03,102 INFO  [main] zookeeper.RecoverableZooKeeper(121): Process identifier=master:38530 connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:03,938 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:385300x0, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null
2015-03-21 02:11:03,940 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(472): master:38530-0x14c3a1908520000 connected
2015-03-21 02:11:04,142 DEBUG [main] zookeeper.ZKUtil(488): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/master
2015-03-21 02:11:04,144 DEBUG [main] zookeeper.ZKUtil(488): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/running
2015-03-21 02:11:04,162 INFO  [RpcServer.responder] ipc.RpcServer$Responder(886): RpcServer.responder: starting
2015-03-21 02:11:04,186 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=0 queue=0
2015-03-21 02:11:04,187 INFO  [RpcServer.listener,port=38530] ipc.RpcServer$Listener(698): RpcServer.listener,port=38530: starting
2015-03-21 02:11:04,187 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=1 queue=0
2015-03-21 02:11:04,206 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=2 queue=0
2015-03-21 02:11:04,209 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=3 queue=0
2015-03-21 02:11:04,209 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=4 queue=0
2015-03-21 02:11:04,212 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=0 queue=0
2015-03-21 02:11:04,214 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=1 queue=1
2015-03-21 02:11:04,215 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=2 queue=0
2015-03-21 02:11:04,215 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=3 queue=1
2015-03-21 02:11:04,216 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=4 queue=0
2015-03-21 02:11:04,233 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=5 queue=1
2015-03-21 02:11:04,239 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=6 queue=0
2015-03-21 02:11:04,244 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=7 queue=1
2015-03-21 02:11:04,250 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=8 queue=0
2015-03-21 02:11:04,255 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=9 queue=1
2015-03-21 02:11:04,256 DEBUG [main] ipc.RpcExecutor(114): Replication Start Handler index=0 queue=0
2015-03-21 02:11:04,257 DEBUG [main] ipc.RpcExecutor(114): Replication Start Handler index=1 queue=0
2015-03-21 02:11:04,257 DEBUG [main] ipc.RpcExecutor(114): Replication Start Handler index=2 queue=0
2015-03-21 02:11:04,268 INFO  [main] http.HttpRequestLog(69): Http request log for http.requests.master is not defined
2015-03-21 02:11:04,273 INFO  [main] http.HttpServer(819): Added global filter 'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-03-21 02:11:04,276 INFO  [main] http.HttpServer(797): Added filter static_user_filter (class=org.apache.hadoop.hbase.http.lib.StaticUserWebFilter$StaticUserFilter) to context master
2015-03-21 02:11:04,277 INFO  [main] http.HttpServer(804): Added filter static_user_filter (class=org.apache.hadoop.hbase.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-03-21 02:11:04,277 INFO  [main] http.HttpServer(804): Added filter static_user_filter (class=org.apache.hadoop.hbase.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-03-21 02:11:04,292 INFO  [main] http.HttpServer(1011): Jetty bound to port 56508
2015-03-21 02:11:04,292 INFO  [main] log.Slf4jLog(67): jetty-6.1.26
2015-03-21 02:11:04,364 INFO  [main] log.Slf4jLog(67): Started SelectChannelConnector@0.0.0.0:56508
2015-03-21 02:11:04,383 INFO  [main] master.HMaster(338): hbase.rootdir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6, hbase.cluster.distributed=false
2015-03-21 02:11:04,400 INFO  [main] master.HMaster(1423): Adding backup master ZNode /hbase/backup-masters/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:04,432 DEBUG [main] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/backup-masters/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:04,499 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeCreated, state=SyncConnected, path=/hbase/master
2015-03-21 02:11:04,512 DEBUG [proserpina:38530.activeMasterManager] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/master
2015-03-21 02:11:04,515 INFO  [proserpina:38530.activeMasterManager] master.ActiveMasterManager(170): Deleting ZNode for /hbase/backup-masters/proserpina.apache.org,38530,1426903862856 from backup master directory
2015-03-21 02:11:04,533 DEBUG [main-EventThread] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/master
2015-03-21 02:11:04,533 DEBUG [main-EventThread] master.ActiveMasterManager(126): A master is now available
2015-03-21 02:11:04,541 WARN  [proserpina:38530.activeMasterManager] hbase.ZNodeClearer(58): Environment variable HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start scripts (Longer MTTR!)
2015-03-21 02:11:04,542 INFO  [proserpina:38530.activeMasterManager] master.ActiveMasterManager(179): Registered Active Master=proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:04,542 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/backup-masters/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:04,657 INFO  [main] client.ConnectionUtils(105): regionserver/proserpina.apache.org/67.195.81.189:0 server-side HConnection retries=350
2015-03-21 02:11:04,658 INFO  [main] ipc.SimpleRpcScheduler(128): Using deadline as user call queue, count=1
2015-03-21 02:11:04,681 INFO  [main] ipc.RpcServer$Listener(567): regionserver/proserpina.apache.org/67.195.81.189:0: started 10 reader(s).
2015-03-21 02:11:04,692 INFO  [main] fs.HFileSystem(252): Added intercepting call to namenode#getBlockLocations so can do block reordering using class class org.apache.hadoop.hbase.fs.HFileSystem$ReorderWALBlocks
2015-03-21 02:11:04,696 INFO  [main] zookeeper.RecoverableZooKeeper(121): Process identifier=regionserver:51019 connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:04,712 DEBUG [main] zookeeper.ZKUtil(486): regionserver:510190x0, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/master
2015-03-21 02:11:04,716 DEBUG [main] zookeeper.ZKUtil(488): regionserver:510190x0, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/running
2015-03-21 02:11:04,721 INFO  [RpcServer.responder] ipc.RpcServer$Responder(886): RpcServer.responder: starting
2015-03-21 02:11:04,716 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): regionserver:510190x0, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null
2015-03-21 02:11:04,724 INFO  [RpcServer.listener,port=51019] ipc.RpcServer$Listener(698): RpcServer.listener,port=51019: starting
2015-03-21 02:11:04,723 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=0 queue=0
2015-03-21 02:11:04,732 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=1 queue=0
2015-03-21 02:11:04,734 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=2 queue=0
2015-03-21 02:11:04,739 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(472): regionserver:51019-0x14c3a1908520001 connected
2015-03-21 02:11:04,739 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=3 queue=0
2015-03-21 02:11:04,740 DEBUG [main] ipc.RpcExecutor(114): B.default Start Handler index=4 queue=0
2015-03-21 02:11:04,741 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=0 queue=0
2015-03-21 02:11:04,741 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=1 queue=1
2015-03-21 02:11:04,743 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=2 queue=0
2015-03-21 02:11:04,744 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=3 queue=1
2015-03-21 02:11:04,744 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=4 queue=0
2015-03-21 02:11:04,745 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=5 queue=1
2015-03-21 02:11:04,745 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=6 queue=0
2015-03-21 02:11:04,746 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=7 queue=1
2015-03-21 02:11:04,754 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=8 queue=0
2015-03-21 02:11:04,755 DEBUG [main] ipc.RpcExecutor(114): Priority Start Handler index=9 queue=1
2015-03-21 02:11:04,755 DEBUG [main] ipc.RpcExecutor(114): Replication Start Handler index=0 queue=0
2015-03-21 02:11:04,756 DEBUG [main] ipc.RpcExecutor(114): Replication Start Handler index=1 queue=0
2015-03-21 02:11:04,756 DEBUG [main] ipc.RpcExecutor(114): Replication Start Handler index=2 queue=0
2015-03-21 02:11:04,757 INFO  [main] http.HttpRequestLog(69): Http request log for http.requests.regionserver is not defined
2015-03-21 02:11:04,759 INFO  [main] http.HttpServer(819): Added global filter 'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-03-21 02:11:04,760 INFO  [main] http.HttpServer(797): Added filter static_user_filter (class=org.apache.hadoop.hbase.http.lib.StaticUserWebFilter$StaticUserFilter) to context regionserver
2015-03-21 02:11:04,760 INFO  [main] http.HttpServer(804): Added filter static_user_filter (class=org.apache.hadoop.hbase.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
2015-03-21 02:11:04,761 INFO  [main] http.HttpServer(804): Added filter static_user_filter (class=org.apache.hadoop.hbase.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
2015-03-21 02:11:04,761 INFO  [IPC Server handler 5 on 42912] blockmanagement.BlockManager(2383): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:54374 is added to blk_1073741826_1002{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a2d75141-06d2-4e32-a0f7-999efc9c94fc:NORMAL|RBW]]} size 42
2015-03-21 02:11:04,764 INFO  [main] http.HttpServer(1011): Jetty bound to port 57648
2015-03-21 02:11:04,764 INFO  [main] log.Slf4jLog(67): jetty-6.1.26
2015-03-21 02:11:04,801 INFO  [main] log.Slf4jLog(67): Started SelectChannelConnector@0.0.0.0:57648
2015-03-21 02:11:04,889 INFO  [RS:0;proserpina:51019] zookeeper.RecoverableZooKeeper(121): Process identifier=hconnection-0x65ff3336 connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:04,890 INFO  [M:0;proserpina:38530] zookeeper.RecoverableZooKeeper(121): Process identifier=hconnection-0x557b528a connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:04,911 DEBUG [RS:0;proserpina:51019-EventThread] zookeeper.ZooKeeperWatcher(388): hconnection-0x65ff33360x0, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null
2015-03-21 02:11:04,913 DEBUG [RS:0;proserpina:51019-EventThread] zookeeper.ZooKeeperWatcher(472): hconnection-0x65ff3336-0x14c3a1908520002 connected
2015-03-21 02:11:04,944 DEBUG [M:0;proserpina:38530-EventThread] zookeeper.ZooKeeperWatcher(388): hconnection-0x557b528a0x0, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null
2015-03-21 02:11:04,945 INFO  [RS:0;proserpina:51019] client.ZooKeeperRegistry(104): ClusterId read in ZooKeeper is null
2015-03-21 02:11:04,945 DEBUG [RS:0;proserpina:51019] client.ConnectionManager$HConnectionImplementation(847): clusterid came back null, using default default-cluster
2015-03-21 02:11:04,946 DEBUG [M:0;proserpina:38530-EventThread] zookeeper.ZooKeeperWatcher(472): hconnection-0x557b528a-0x14c3a1908520003 connected
2015-03-21 02:11:04,946 INFO  [M:0;proserpina:38530] client.ZooKeeperRegistry(104): ClusterId read in ZooKeeper is null
2015-03-21 02:11:04,948 DEBUG [M:0;proserpina:38530] client.ConnectionManager$HConnectionImplementation(847): clusterid came back null, using default default-cluster
2015-03-21 02:11:05,020 DEBUG [RS:0;proserpina:51019] ipc.AbstractRpcClient(105): Codec=org.apache.hadoop.hbase.codec.KeyValueCodec@3f8429a7, compressor=null, tcpKeepAlive=true, tcpNoDelay=true, connectTO=10000, readTO=20000, writeTO=60000, minIdleTimeBeforeClose=120000, maxRetries=0, fallbackAllowed=true, bind address=null
2015-03-21 02:11:05,020 DEBUG [M:0;proserpina:38530] ipc.AbstractRpcClient(105): Codec=org.apache.hadoop.hbase.codec.KeyValueCodec@1c0ba133, compressor=null, tcpKeepAlive=true, tcpNoDelay=true, connectTO=10000, readTO=20000, writeTO=60000, minIdleTimeBeforeClose=120000, maxRetries=0, fallbackAllowed=true, bind address=null
2015-03-21 02:11:05,021 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(152): Starting async Hbase RPC client
2015-03-21 02:11:05,021 DEBUG [M:0;proserpina:38530] ipc.AsyncRpcClient(152): Starting async Hbase RPC client
2015-03-21 02:11:05,021 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(131): Create NioEventLoopGroup with maxThreads = 0
2015-03-21 02:11:05,106 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(106): Create global event loop group NioEventLoopGroup
2015-03-21 02:11:05,107 DEBUG [M:0;proserpina:38530] ipc.AsyncRpcClient(163): Use global event loop group NioEventLoopGroup
2015-03-21 02:11:05,107 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(163): Use global event loop group NioEventLoopGroup
2015-03-21 02:11:05,173 DEBUG [proserpina:38530.activeMasterManager] util.FSUtils(864): Created cluster ID file at hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/hbase.id with ID: 9500695b-0220-487d-9d12-037e9eed7bc7
2015-03-21 02:11:05,236 INFO  [proserpina:38530.activeMasterManager] master.MasterFileSystem(507): BOOTSTRAP: creating hbase:meta region
2015-03-21 02:11:05,241 INFO  [proserpina:38530.activeMasterManager] regionserver.HRegion(6001): creating HRegion hbase:meta HTD == 'hbase:meta', {TABLE_ATTRIBUTES => {IS_META => 'true', coprocessor$1 => '|org.apache.hadoop.hbase.coprocessor.MultiRowMutationEndpoint|536870911|'}, {NAME => 'info', DATA_BLOCK_ENCODING => 'NONE', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'NONE', VERSIONS => '3', TTL => 'FOREVER', MIN_VERSIONS => '0', CACHE_DATA_IN_L1 => 'true', KEEP_DELETED_CELLS => 'FALSE', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'table', DATA_BLOCK_ENCODING => 'NONE', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', COMPRESSION => 'NONE', VERSIONS => '10', TTL => 'FOREVER', MIN_VERSIONS => '0', CACHE_DATA_IN_L1 => 'true', KEEP_DELETED_CELLS => 'FALSE', BLOCKSIZE => '8192', IN_MEMORY => 'true', BLOCKCACHE => 'true'} RootDir = hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6 Table name == hbase:meta
2015-03-21 02:11:05,303 INFO  [IPC Server handler 8 on 42912] blockmanagement.BlockManager(2383): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:54374 is added to blk_1073741827_1003{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-20704df4-ae22-40c7-8dcd-b411672f6980:NORMAL|RBW]]} size 0
2015-03-21 02:11:05,312 DEBUG [proserpina:38530.activeMasterManager] regionserver.HRegion(770): Instantiated hbase:meta,,1.1588230740
2015-03-21 02:11:05,469 INFO  [StoreOpener-1588230740-1] hfile.CacheConfig(470): Allocating LruBlockCache size=995.60 MB, blockSize=64 KB
2015-03-21 02:11:05,498 INFO  [StoreOpener-1588230740-1] hfile.CacheConfig(260): blockCache=LruBlockCache{blockCount=0, currentSize=1071760, freeSize=1042890544, maxSize=1043962304, heapSize=1071760, minSize=991764160, minFactor=0.95, multiSize=495882080, multiFactor=0.5, singleSize=247941040, singleFactor=0.25}, cacheDataOnRead=false, cacheDataOnWrite=false, cacheIndexesOnWrite=false, cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false, prefetchOnOpen=false
2015-03-21 02:11:05,510 INFO  [StoreOpener-1588230740-1] compactions.CompactionConfiguration(97): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; major period 604800000, major jitter 0.500000, min locality to compact 0.000000
2015-03-21 02:11:05,519 DEBUG [StoreOpener-1588230740-1] regionserver.HRegionFileSystem(201): No StoreFiles for: hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/data/hbase/meta/1588230740/info
2015-03-21 02:11:05,531 DEBUG [StoreOpener-1588230740-1] util.ChecksumType$2(70): org.apache.hadoop.util.PureJavaCrc32 available
2015-03-21 02:11:05,531 DEBUG [StoreOpener-1588230740-1] util.ChecksumType$3(113): org.apache.hadoop.util.PureJavaCrc32C available
2015-03-21 02:11:05,539 INFO  [StoreOpener-1588230740-1] hfile.CacheConfig(260): blockCache=LruBlockCache{blockCount=0, currentSize=1071760, freeSize=1042890544, maxSize=1043962304, heapSize=1071760, minSize=991764160, minFactor=0.95, multiSize=495882080, multiFactor=0.5, singleSize=247941040, singleFactor=0.25}, cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false, cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false, prefetchOnOpen=false
2015-03-21 02:11:05,542 INFO  [StoreOpener-1588230740-1] compactions.CompactionConfiguration(97): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; major period 604800000, major jitter 0.500000, min locality to compact 0.000000
2015-03-21 02:11:05,547 DEBUG [StoreOpener-1588230740-1] regionserver.HRegionFileSystem(201): No StoreFiles for: hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/data/hbase/meta/1588230740/table
2015-03-21 02:11:05,558 DEBUG [proserpina:38530.activeMasterManager] regionserver.HRegion(3910): Found 0 recovered edits file(s) under hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/data/hbase/meta/1588230740
2015-03-21 02:11:05,581 DEBUG [proserpina:38530.activeMasterManager] regionserver.FlushLargeStoresPolicy(56): hbase.hregion.percolumnfamilyflush.size.lower.bound is not specified, use global config(16777216) instead
2015-03-21 02:11:05,593 DEBUG [proserpina:38530.activeMasterManager] wal.WALSplitter(712): Wrote region seqId=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/data/hbase/meta/1588230740/recovered.edits/2.seqid to file, newSeqId=2, maxSeqId=0
2015-03-21 02:11:05,593 INFO  [proserpina:38530.activeMasterManager] regionserver.HRegion(898): Onlined 1588230740; next sequenceid=2
2015-03-21 02:11:05,594 DEBUG [proserpina:38530.activeMasterManager] regionserver.HRegion(1357): Closing hbase:meta,,1.1588230740: disabling compactions & flushes
2015-03-21 02:11:05,594 DEBUG [proserpina:38530.activeMasterManager] regionserver.HRegion(1384): Updates disabled for region hbase:meta,,1.1588230740
2015-03-21 02:11:05,609 INFO  [StoreCloserThread-hbase:meta,,1.1588230740-1] regionserver.HStore(879): Closed info
2015-03-21 02:11:05,610 INFO  [StoreCloserThread-hbase:meta,,1.1588230740-1] regionserver.HStore(879): Closed table
2015-03-21 02:11:05,610 INFO  [proserpina:38530.activeMasterManager] regionserver.HRegion(1476): Closed hbase:meta,,1.1588230740
2015-03-21 02:11:05,677 INFO  [IPC Server handler 7 on 42912] blockmanagement.BlockManager(2383): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:54374 is added to blk_1073741828_1004{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a2d75141-06d2-4e32-a0f7-999efc9c94fc:NORMAL|RBW]]} size 0
2015-03-21 02:11:05,693 DEBUG [proserpina:38530.activeMasterManager] util.FSTableDescriptors(718): Wrote descriptor into: hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/data/hbase/meta/.tabledesc/.tableinfo.0000000001
2015-03-21 02:11:05,720 INFO  [proserpina:38530.activeMasterManager] fs.HFileSystem(252): Added intercepting call to namenode#getBlockLocations so can do block reordering using class class org.apache.hadoop.hbase.fs.HFileSystem$ReorderWALBlocks
2015-03-21 02:11:05,728 DEBUG [proserpina:38530.activeMasterManager] coordination.ZKSplitLogManagerCoordination(886): Distributed log replay=true
2015-03-21 02:11:05,736 INFO  [proserpina:38530.activeMasterManager] coordination.ZKSplitLogManagerCoordination(599): Found 0 orphan tasks and 0 rescan nodes
2015-03-21 02:11:05,738 DEBUG [proserpina:38530.activeMasterManager] util.FSTableDescriptors(222): Fetching table descriptors from the filesystem.
2015-03-21 02:11:05,772 INFO  [proserpina:38530.activeMasterManager] zookeeper.RecoverableZooKeeper(121): Process identifier=hconnection-0x28f86af6 connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:05,795 DEBUG [proserpina:38530.activeMasterManager-EventThread] zookeeper.ZooKeeperWatcher(388): hconnection-0x28f86af60x0, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null
2015-03-21 02:11:05,796 DEBUG [proserpina:38530.activeMasterManager-EventThread] zookeeper.ZooKeeperWatcher(472): hconnection-0x28f86af6-0x14c3a1908520004 connected
2015-03-21 02:11:05,802 DEBUG [proserpina:38530.activeMasterManager] ipc.AbstractRpcClient(105): Codec=org.apache.hadoop.hbase.codec.KeyValueCodec@38c94d89, compressor=null, tcpKeepAlive=true, tcpNoDelay=true, connectTO=10000, readTO=20000, writeTO=60000, minIdleTimeBeforeClose=120000, maxRetries=0, fallbackAllowed=true, bind address=null
2015-03-21 02:11:05,803 DEBUG [proserpina:38530.activeMasterManager] ipc.AsyncRpcClient(152): Starting async Hbase RPC client
2015-03-21 02:11:05,804 DEBUG [proserpina:38530.activeMasterManager] ipc.AsyncRpcClient(163): Use global event loop group NioEventLoopGroup
2015-03-21 02:11:05,826 INFO  [proserpina:38530.activeMasterManager] balancer.StochasticLoadBalancer(135): loading config
2015-03-21 02:11:05,846 DEBUG [proserpina:38530.activeMasterManager] zookeeper.ZKUtil(488): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/balancer
2015-03-21 02:11:05,894 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeCreated, state=SyncConnected, path=/hbase/running
2015-03-21 02:11:05,895 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeCreated, state=SyncConnected, path=/hbase/running
2015-03-21 02:11:05,896 INFO  [proserpina:38530.activeMasterManager] master.HMaster(548): Server active/primary master=proserpina.apache.org,38530,1426903862856, sessionid=0x14c3a1908520000, setting cluster-up flag (Was=false)
2015-03-21 02:11:05,898 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(745): ClusterId : 9500695b-0220-487d-9d12-037e9eed7bc7
2015-03-21 02:11:05,912 DEBUG [M:0;proserpina:38530] procedure.RegionServerProcedureManagerHost(44): Procedure online-snapshot is initializing
2015-03-21 02:11:05,899 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(745): ClusterId : 9500695b-0220-487d-9d12-037e9eed7bc7
2015-03-21 02:11:05,913 DEBUG [RS:0;proserpina:51019] procedure.RegionServerProcedureManagerHost(44): Procedure online-snapshot is initializing
2015-03-21 02:11:05,961 DEBUG [M:0;proserpina:38530] zookeeper.RecoverableZooKeeper(531): Node /hbase/online-snapshot already exists
2015-03-21 02:11:05,977 DEBUG [RS:0;proserpina:51019] zookeeper.RecoverableZooKeeper(531): Node /hbase/online-snapshot/acquired already exists
2015-03-21 02:11:05,994 DEBUG [M:0;proserpina:38530] zookeeper.RecoverableZooKeeper(531): Node /hbase/online-snapshot/acquired already exists
2015-03-21 02:11:06,044 DEBUG [proserpina:38530.activeMasterManager] zookeeper.RecoverableZooKeeper(531): Node /hbase/online-snapshot/reached already exists
2015-03-21 02:11:06,070 INFO  [proserpina:38530.activeMasterManager] procedure.ZKProcedureUtil(271): Clearing all procedure znodes: /hbase/online-snapshot/acquired /hbase/online-snapshot/reached /hbase/online-snapshot/abort
2015-03-21 02:11:06,070 DEBUG [M:0;proserpina:38530] procedure.RegionServerProcedureManagerHost(46): Procedure online-snapshot is initialized
2015-03-21 02:11:06,070 DEBUG [RS:0;proserpina:51019] procedure.RegionServerProcedureManagerHost(46): Procedure online-snapshot is initialized
2015-03-21 02:11:06,071 DEBUG [M:0;proserpina:38530] procedure.RegionServerProcedureManagerHost(44): Procedure flush-table-proc is initializing
2015-03-21 02:11:06,071 DEBUG [RS:0;proserpina:51019] procedure.RegionServerProcedureManagerHost(44): Procedure flush-table-proc is initializing
2015-03-21 02:11:06,136 DEBUG [RS:0;proserpina:51019] zookeeper.RecoverableZooKeeper(531): Node /hbase/flush-table-proc already exists
2015-03-21 02:11:06,136 DEBUG [proserpina:38530.activeMasterManager] procedure.ZKProcedureCoordinatorRpcs(238): Starting the controller for procedure member:proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,169 DEBUG [RS:0;proserpina:51019] zookeeper.RecoverableZooKeeper(531): Node /hbase/flush-table-proc/acquired already exists
2015-03-21 02:11:06,169 DEBUG [proserpina:38530.activeMasterManager] zookeeper.RecoverableZooKeeper(531): Node /hbase/flush-table-proc/acquired already exists
2015-03-21 02:11:06,181 DEBUG [RS:0;proserpina:51019] zookeeper.RecoverableZooKeeper(531): Node /hbase/flush-table-proc/reached already exists
2015-03-21 02:11:06,189 DEBUG [proserpina:38530.activeMasterManager] zookeeper.RecoverableZooKeeper(531): Node /hbase/flush-table-proc/reached already exists
2015-03-21 02:11:06,198 INFO  [proserpina:38530.activeMasterManager] procedure.ZKProcedureUtil(271): Clearing all procedure znodes: /hbase/flush-table-proc/acquired /hbase/flush-table-proc/reached /hbase/flush-table-proc/abort
2015-03-21 02:11:06,198 DEBUG [M:0;proserpina:38530] zookeeper.RecoverableZooKeeper(531): Node /hbase/flush-table-proc/abort already exists
2015-03-21 02:11:06,200 DEBUG [RS:0;proserpina:51019] procedure.RegionServerProcedureManagerHost(46): Procedure flush-table-proc is initialized
2015-03-21 02:11:06,200 DEBUG [M:0;proserpina:38530] procedure.RegionServerProcedureManagerHost(46): Procedure flush-table-proc is initialized
2015-03-21 02:11:06,204 DEBUG [proserpina:38530.activeMasterManager] procedure.ZKProcedureCoordinatorRpcs(238): Starting the controller for procedure member:proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,215 INFO  [M:0;proserpina:38530] regionserver.MemStoreFlusher(124): globalMemStoreLimit=995.6 M, globalMemStoreLimitLowMark=945.8 M, maxHeap=2.4 G
2015-03-21 02:11:06,219 INFO  [RS:0;proserpina:51019] regionserver.MemStoreFlusher(124): globalMemStoreLimit=995.6 M, globalMemStoreLimitLowMark=945.8 M, maxHeap=2.4 G
2015-03-21 02:11:06,229 INFO  [M:0;proserpina:38530] compactions.PressureAwareCompactionThroughputController(175): Compaction throughput configurations, higher bound: 20.00 MB/sec, lower bound 10.00 MB/sec, off peak: unlimited, tuning period: 60000 ms
2015-03-21 02:11:06,229 INFO  [RS:0;proserpina:51019] compactions.PressureAwareCompactionThroughputController(175): Compaction throughput configurations, higher bound: 20.00 MB/sec, lower bound 10.00 MB/sec, off peak: unlimited, tuning period: 60000 ms
2015-03-21 02:11:06,232 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer$CompactionChecker(1473): CompactionChecker runs every 1sec
2015-03-21 02:11:06,236 DEBUG [RS:0;proserpina:51019] ipc.AbstractRpcClient(105): Codec=org.apache.hadoop.hbase.codec.KeyValueCodec@190f51a, compressor=null, tcpKeepAlive=true, tcpNoDelay=true, connectTO=10000, readTO=20000, writeTO=60000, minIdleTimeBeforeClose=120000, maxRetries=0, fallbackAllowed=true, bind address=proserpina.apache.org/67.195.81.189:0
2015-03-21 02:11:06,236 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(152): Starting async Hbase RPC client
2015-03-21 02:11:06,237 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(163): Use global event loop group NioEventLoopGroup
2015-03-21 02:11:06,241 INFO  [M:0;proserpina:38530] regionserver.HRegionServer$CompactionChecker(1473): CompactionChecker runs every 1sec
2015-03-21 02:11:06,242 DEBUG [M:0;proserpina:38530] ipc.AbstractRpcClient(105): Codec=org.apache.hadoop.hbase.codec.KeyValueCodec@181dbfc, compressor=null, tcpKeepAlive=true, tcpNoDelay=true, connectTO=10000, readTO=20000, writeTO=60000, minIdleTimeBeforeClose=120000, maxRetries=0, fallbackAllowed=true, bind address=proserpina.apache.org/67.195.81.189:0
2015-03-21 02:11:06,242 DEBUG [M:0;proserpina:38530] ipc.AsyncRpcClient(152): Starting async Hbase RPC client
2015-03-21 02:11:06,242 DEBUG [M:0;proserpina:38530] ipc.AsyncRpcClient(163): Use global event loop group NioEventLoopGroup
2015-03-21 02:11:06,243 DEBUG [RS:0;proserpina:51019] regionserver.ShutdownHook(87): Installed shutdown hook thread: Shutdownhook:RS:0;proserpina:51019
2015-03-21 02:11:06,247 DEBUG [M:0;proserpina:38530] regionserver.ShutdownHook(87): Installed shutdown hook thread: Shutdownhook:M:0;proserpina:38530
2015-03-21 02:11:06,256 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/rs
2015-03-21 02:11:06,259 DEBUG [RS:0;proserpina:51019] zookeeper.ZKUtil(486): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,262 DEBUG [M:0;proserpina:38530] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,261 DEBUG [main-EventThread] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,265 DEBUG [main-EventThread] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,267 INFO  [proserpina:38530.activeMasterManager] master.MasterCoprocessorHost(86): System coprocessor loading is enabled
2015-03-21 02:11:06,270 DEBUG [main-EventThread] zookeeper.RegionServerTracker(93): Added tracking of RS /hbase/rs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,271 DEBUG [main-EventThread] zookeeper.RegionServerTracker(93): Added tracking of RS /hbase/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,273 INFO  [RS:0;proserpina:51019] regionserver.RegionServerCoprocessorHost(65): System coprocessor loading is enabled
2015-03-21 02:11:06,276 INFO  [RS:0;proserpina:51019] regionserver.RegionServerCoprocessorHost(66): Table coprocessor loading is enabled
2015-03-21 02:11:06,273 INFO  [M:0;proserpina:38530] regionserver.RegionServerCoprocessorHost(65): System coprocessor loading is enabled
2015-03-21 02:11:06,277 INFO  [M:0;proserpina:38530] regionserver.RegionServerCoprocessorHost(66): Table coprocessor loading is enabled
2015-03-21 02:11:06,314 DEBUG [proserpina:38530.activeMasterManager] master.HMaster(1994): Registered master coprocessor service: service=AccessControlService
2015-03-21 02:11:06,317 DEBUG [M:0;proserpina:38530] zookeeper.ZKUtil(488): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/acl
2015-03-21 02:11:06,318 INFO  [M:0;proserpina:38530] coprocessor.CoprocessorHost(156): System coprocessor org.apache.hadoop.hbase.security.access.AccessController was loaded successfully with priority (536870911).
2015-03-21 02:11:06,318 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(2209): reportForDuty to master=proserpina.apache.org,38530,1426903862856 with port=38530, startcode=1426903862856
2015-03-21 02:11:06,336 DEBUG [RS:0;proserpina:51019] zookeeper.ZKUtil(488): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/acl
2015-03-21 02:11:06,337 INFO  [RS:0;proserpina:51019] coprocessor.CoprocessorHost(156): System coprocessor org.apache.hadoop.hbase.security.access.AccessController was loaded successfully with priority (536870911).
2015-03-21 02:11:06,335 INFO  [proserpina:38530.activeMasterManager] coprocessor.CoprocessorHost(156): System coprocessor org.apache.hadoop.hbase.security.access.AccessController was loaded successfully with priority (536870911).
2015-03-21 02:11:06,338 INFO  [proserpina:38530.activeMasterManager] coprocessor.CoprocessorHost(156): System coprocessor org.apache.hadoop.hbase.security.access.SecureTestUtil$MasterSyncObserver was loaded successfully with priority (536870912).
2015-03-21 02:11:06,340 DEBUG [M:0;proserpina:38530] regionserver.HRegionServer(2225): Master is not running yet
2015-03-21 02:11:06,340 WARN  [M:0;proserpina:38530] regionserver.HRegionServer(871): reportForDuty failed; sleeping and then retrying.
2015-03-21 02:11:06,340 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(2209): reportForDuty to master=proserpina.apache.org,38530,1426903862856 with port=51019, startcode=1426903864687
2015-03-21 02:11:06,342 DEBUG [proserpina:38530.activeMasterManager] executor.ExecutorService(91): Starting executor service name=MASTER_OPEN_REGION-proserpina:38530, corePoolSize=5, maxPoolSize=5
2015-03-21 02:11:06,342 DEBUG [proserpina:38530.activeMasterManager] executor.ExecutorService(91): Starting executor service name=MASTER_CLOSE_REGION-proserpina:38530, corePoolSize=5, maxPoolSize=5
2015-03-21 02:11:06,343 DEBUG [proserpina:38530.activeMasterManager] executor.ExecutorService(91): Starting executor service name=MASTER_SERVER_OPERATIONS-proserpina:38530, corePoolSize=5, maxPoolSize=5
2015-03-21 02:11:06,343 DEBUG [proserpina:38530.activeMasterManager] executor.ExecutorService(91): Starting executor service name=MASTER_META_SERVER_OPERATIONS-proserpina:38530, corePoolSize=5, maxPoolSize=5
2015-03-21 02:11:06,343 DEBUG [proserpina:38530.activeMasterManager] executor.ExecutorService(91): Starting executor service name=M_LOG_REPLAY_OPS-proserpina:38530, corePoolSize=10, maxPoolSize=10
2015-03-21 02:11:06,344 DEBUG [proserpina:38530.activeMasterManager] executor.ExecutorService(91): Starting executor service name=MASTER_TABLE_OPERATIONS-proserpina:38530, corePoolSize=1, maxPoolSize=1
2015-03-21 02:11:06,346 DEBUG [proserpina:38530.activeMasterManager] cleaner.CleanerChore(91): initialize cleaner=org.apache.hadoop.hbase.master.cleaner.TimeToLiveLogCleaner
2015-03-21 02:11:06,347 INFO  [proserpina:38530.activeMasterManager] zookeeper.RecoverableZooKeeper(121): Process identifier=replicationLogCleaner connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:06,361 DEBUG [proserpina:38530.activeMasterManager-EventThread] zookeeper.ZooKeeperWatcher(388): replicationLogCleaner0x0, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null
2015-03-21 02:11:06,367 DEBUG [proserpina:38530.activeMasterManager-EventThread] zookeeper.ZooKeeperWatcher(472): replicationLogCleaner-0x14c3a1908520005 connected
2015-03-21 02:11:06,436 DEBUG [proserpina:38530.activeMasterManager] cleaner.CleanerChore(91): initialize cleaner=org.apache.hadoop.hbase.replication.master.ReplicationLogCleaner
2015-03-21 02:11:06,449 DEBUG [proserpina:38530.activeMasterManager] cleaner.CleanerChore(91): initialize cleaner=org.apache.hadoop.hbase.master.snapshot.SnapshotLogCleaner
2015-03-21 02:11:06,452 DEBUG [proserpina:38530.activeMasterManager] cleaner.CleanerChore(91): initialize cleaner=org.apache.hadoop.hbase.master.cleaner.HFileLinkCleaner
2015-03-21 02:11:06,457 DEBUG [proserpina:38530.activeMasterManager] cleaner.CleanerChore(91): initialize cleaner=org.apache.hadoop.hbase.master.snapshot.SnapshotHFileCleaner
2015-03-21 02:11:06,459 DEBUG [proserpina:38530.activeMasterManager] cleaner.CleanerChore(91): initialize cleaner=org.apache.hadoop.hbase.master.cleaner.TimeToLiveHFileCleaner
2015-03-21 02:11:06,460 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(2209): reportForDuty to master=proserpina.apache.org,38530,1426903862856 with port=38530, startcode=1426903862856
2015-03-21 02:11:06,468 INFO  [proserpina:38530.activeMasterManager] master.ServerManager(979): Waiting for region servers count to settle; currently checked in 0, slept for 0 ms, expecting minimum of 1, maximum of 1, timeout of 4500 ms, interval of 1500 ms.
2015-03-21 02:11:06,485 INFO  [M:0;proserpina:38530] master.ServerManager(444): Registering server=proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,519 INFO  [proserpina:38530.activeMasterManager] master.ServerManager(996): Finished waiting for region servers count to settle; checked in 1, slept for 60 ms, expecting minimum of 1, maximum of 1, master is running
2015-03-21 02:11:06,523 INFO  [proserpina:38530.activeMasterManager] master.ServerManager(444): Registering server=proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,524 INFO  [proserpina:38530.activeMasterManager] master.HMaster(645): Registered server found up in zk but who has not yet reported in: proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,526 DEBUG [RpcServer.listener,port=38530] ipc.RpcServer$Listener(809): RpcServer.listener,port=38530: connection from 67.195.81.189:42362; # active connections: 1
2015-03-21 02:11:06,527 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(1303): Config from master: hbase.rootdir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6
2015-03-21 02:11:06,527 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(1303): Config from master: fs.defaultFS=hdfs://localhost:42912
2015-03-21 02:11:06,527 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(1303): Config from master: hbase.master.info.port=56508
2015-03-21 02:11:06,527 WARN  [M:0;proserpina:38530] hbase.ZNodeClearer(58): Environment variable HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start scripts (Longer MTTR!)
2015-03-21 02:11:06,528 INFO  [M:0;proserpina:38530] hfile.CacheConfig(260): blockCache=LruBlockCache{blockCount=0, currentSize=1071760, freeSize=1042890544, maxSize=1043962304, heapSize=1071760, minSize=991764160, minFactor=0.95, multiSize=495882080, multiFactor=0.5, singleSize=247941040, singleFactor=0.25}, cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false, cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false, prefetchOnOpen=false
2015-03-21 02:11:06,531 DEBUG [M:0;proserpina:38530] regionserver.HRegionServer(1570): logdir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,536 DEBUG [proserpina:38530.activeMasterManager] zookeeper.ZKUtil(745): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Unable to get data of znode /hbase/meta-region-server because node does not exist (not an error)
2015-03-21 02:11:06,588 DEBUG [M:0;proserpina:38530] regionserver.Replication(142): ReplicationStatisticsThread 300
2015-03-21 02:11:06,604 INFO  [M:0;proserpina:38530] wal.WALFactory(143): Instantiating WALProvider of type class org.apache.hadoop.hbase.wal.DefaultWALProvider
2015-03-21 02:11:06,605 DEBUG [AsyncRpcChannel-pool2-t1] ipc.AsyncRpcChannel(487): Use SIMPLE authentication for service RegionServerStatusService, sasl=false
2015-03-21 02:11:06,642 INFO  [M:0;proserpina:38530] wal.FSHLog(549): WAL configuration: blocksize=128 MB, rollsize=121.60 MB, prefix=proserpina.apache.org%2C38530%2C1426903862856.default, suffix=, logDir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,38530,1426903862856, archiveDir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/oldWALs
2015-03-21 02:11:06,679 INFO  [RpcServer.reader=1,bindAddress=proserpina.apache.org,port=38530] ipc.RpcServer$Connection(1640): Connection from 67.195.81.189 port: 42362 with version info: version: "2.0.0-SNAPSHOT" url: "git://proserpina.apache.org/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build" revision: "09151911679a608db31cca63c25cfd52818a311c" user: "jenkins" date: "Sat Mar 21 00:59:39 UTC 2015" src_checksum: "418b9105ad07f6f87c0e478355cabaa1"
2015-03-21 02:11:06,713 INFO  [M:0;proserpina:38530] wal.FSHLog(1494): Slow sync cost: 30 ms, current pipeline: []
2015-03-21 02:11:06,715 INFO  [M:0;proserpina:38530] wal.FSHLog(971): New WAL /user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,38530,1426903862856/proserpina.apache.org%2C38530%2C1426903862856.default.1426903866643
2015-03-21 02:11:06,715 INFO  [B.defaultRpcServer.handler=2,queue=0,port=38530] master.ServerManager(444): Registering server=proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,740 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(1303): Config from master: hbase.rootdir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6
2015-03-21 02:11:06,745 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(1303): Config from master: fs.defaultFS=hdfs://localhost:42912
2015-03-21 02:11:06,745 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(1303): Config from master: hbase.master.info.port=56508
2015-03-21 02:11:06,746 WARN  [RS:0;proserpina:51019] hbase.ZNodeClearer(58): Environment variable HBASE_ZNODE_FILE not set; znodes will not be cleared on crash by start scripts (Longer MTTR!)
2015-03-21 02:11:06,746 INFO  [RS:0;proserpina:51019] hfile.CacheConfig(260): blockCache=LruBlockCache{blockCount=0, currentSize=1071760, freeSize=1042890544, maxSize=1043962304, heapSize=1071760, minSize=991764160, minFactor=0.95, multiSize=495882080, multiFactor=0.5, singleSize=247941040, singleFactor=0.25}, cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false, cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false, prefetchOnOpen=false
2015-03-21 02:11:06,747 DEBUG [RS:0;proserpina:51019] regionserver.HRegionServer(1570): logdir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,793 DEBUG [RS:0;proserpina:51019] regionserver.Replication(142): ReplicationStatisticsThread 300
2015-03-21 02:11:06,796 INFO  [RS:0;proserpina:51019] wal.WALFactory(143): Instantiating WALProvider of type class org.apache.hadoop.hbase.wal.DefaultWALProvider
2015-03-21 02:11:06,797 INFO  [M:0;proserpina:38530] regionserver.MetricsRegionServerWrapperImpl(110): Computing regionserver metrics every 5000 milliseconds
2015-03-21 02:11:06,810 INFO  [RS:0;proserpina:51019] wal.FSHLog(549): WAL configuration: blocksize=128 MB, rollsize=121.60 MB, prefix=proserpina.apache.org%2C51019%2C1426903864687.default, suffix=, logDir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,51019,1426903864687, archiveDir=hdfs://localhost:42912/user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/oldWALs
2015-03-21 02:11:06,816 DEBUG [M:0;proserpina:38530] executor.ExecutorService(91): Starting executor service name=RS_OPEN_REGION-proserpina:38530, corePoolSize=3, maxPoolSize=3
2015-03-21 02:11:06,816 DEBUG [M:0;proserpina:38530] executor.ExecutorService(91): Starting executor service name=RS_OPEN_META-proserpina:38530, corePoolSize=1, maxPoolSize=1
2015-03-21 02:11:06,827 DEBUG [M:0;proserpina:38530] executor.ExecutorService(91): Starting executor service name=RS_CLOSE_REGION-proserpina:38530, corePoolSize=3, maxPoolSize=3
2015-03-21 02:11:06,830 DEBUG [M:0;proserpina:38530] executor.ExecutorService(91): Starting executor service name=RS_CLOSE_META-proserpina:38530, corePoolSize=1, maxPoolSize=1
2015-03-21 02:11:06,830 DEBUG [M:0;proserpina:38530] executor.ExecutorService(91): Starting executor service name=RS_LOG_REPLAY_OPS-proserpina:38530, corePoolSize=2, maxPoolSize=2
2015-03-21 02:11:06,831 DEBUG [M:0;proserpina:38530] executor.ExecutorService(91): Starting executor service name=RS_REGION_REPLICA_FLUSH_OPS-proserpina:38530, corePoolSize=3, maxPoolSize=3
2015-03-21 02:11:06,849 DEBUG [M:0;proserpina:38530] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,850 DEBUG [M:0;proserpina:38530] zookeeper.ZKUtil(486): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,850 INFO  [M:0;proserpina:38530] regionserver.ReplicationSourceManager(227): Current list of replicators: [proserpina.apache.org,51019,1426903864687, proserpina.apache.org,38530,1426903862856] other RSs: [proserpina.apache.org,51019,1426903864687, proserpina.apache.org,38530,1426903862856]
2015-03-21 02:11:06,860 INFO  [RS:0;proserpina:51019] wal.FSHLog(1494): Slow sync cost: 40 ms, current pipeline: []
2015-03-21 02:11:06,860 INFO  [RS:0;proserpina:51019] wal.FSHLog(971): New WAL /user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,51019,1426903864687/proserpina.apache.org%2C51019%2C1426903864687.default.1426903866811
2015-03-21 02:11:06,869 INFO  [RS:0;proserpina:51019] regionserver.MetricsRegionServerWrapperImpl(110): Computing regionserver metrics every 5000 milliseconds
2015-03-21 02:11:06,882 DEBUG [RS:0;proserpina:51019] executor.ExecutorService(91): Starting executor service name=RS_OPEN_REGION-proserpina:51019, corePoolSize=3, maxPoolSize=3
2015-03-21 02:11:06,884 DEBUG [RS:0;proserpina:51019] executor.ExecutorService(91): Starting executor service name=RS_OPEN_META-proserpina:51019, corePoolSize=1, maxPoolSize=1
2015-03-21 02:11:06,885 DEBUG [RS:0;proserpina:51019] executor.ExecutorService(91): Starting executor service name=RS_CLOSE_REGION-proserpina:51019, corePoolSize=3, maxPoolSize=3
2015-03-21 02:11:06,886 DEBUG [RS:0;proserpina:51019] executor.ExecutorService(91): Starting executor service name=RS_CLOSE_META-proserpina:51019, corePoolSize=1, maxPoolSize=1
2015-03-21 02:11:06,886 DEBUG [RS:0;proserpina:51019] executor.ExecutorService(91): Starting executor service name=RS_LOG_REPLAY_OPS-proserpina:51019, corePoolSize=2, maxPoolSize=2
2015-03-21 02:11:06,887 DEBUG [RS:0;proserpina:51019] executor.ExecutorService(91): Starting executor service name=RS_REGION_REPLICA_FLUSH_OPS-proserpina:51019, corePoolSize=3, maxPoolSize=3
2015-03-21 02:11:06,894 DEBUG [RS:0;proserpina:51019] zookeeper.ZKUtil(486): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:06,895 DEBUG [RS:0;proserpina:51019] zookeeper.ZKUtil(486): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Set watcher on existing znode=/hbase/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:06,895 INFO  [RS:0;proserpina:51019] regionserver.ReplicationSourceManager(227): Current list of replicators: [proserpina.apache.org,51019,1426903864687, proserpina.apache.org,38530,1426903862856] other RSs: [proserpina.apache.org,51019,1426903864687, proserpina.apache.org,38530,1426903862856]
2015-03-21 02:11:06,963 INFO  [M:0;proserpina:38530] zookeeper.RecoverableZooKeeper(121): Process identifier=hconnection-0x51d528bc connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:06,964 INFO  [RS:0;proserpina:51019] zookeeper.RecoverableZooKeeper(121): Process identifier=hconnection-0x2cd18c22 connecting to ZooKeeper ensemble=localhost:55239
2015-03-21 02:11:06,967 DEBUG [RS:0;proserpina:51019] coprocessor.CoprocessorHost(269): Stop coprocessor org.apache.hadoop.hbase.security.access.AccessController
2015-03-21 02:11:06,967 DEBUG [M:0;proserpina:38530] coprocessor.CoprocessorHost(269): Stop coprocessor org.apache.hadoop.hbase.security.access.AccessController
2015-03-21 02:11:06,968 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(1819): STOPPED: Failed initialization
2015-03-21 02:11:06,968 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(1819): STOPPED: Failed initialization
2015-03-21 02:11:06,969 ERROR [M:0;proserpina:38530] regionserver.HRegionServer(2863): Failed init
java.io.IOException: java.lang.reflect.InvocationTargetException
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:239)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:217)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:118)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSink.<init>(ReplicationSink.java:90)
	at org.apache.hadoop.hbase.replication.regionserver.Replication.startReplicationService(Replication.java:213)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.startServiceThreads(HRegionServer.java:1684)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.handleReportForDutyResponse(HRegionServer.java:1323)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:874)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:237)
	... 8 more
Caused by: java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method)
	at java.lang.Thread.start(Thread.java:713)
	at org.apache.zookeeper.ClientCnxn.start(ClientCnxn.java:405)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:450)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:380)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.checkZk(RecoverableZooKeeper.java:142)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.<init>(RecoverableZooKeeper.java:129)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.connect(ZKUtil.java:155)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:163)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:131)
	at org.apache.hadoop.hbase.client.ZooKeeperKeepAliveConnection.<init>(ZooKeeperKeepAliveConnection.java:43)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.getKeepAliveZooKeeperWatcher(ConnectionManager.java:1617)
	at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:101)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.retrieveClusterId(ConnectionManager.java:844)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.<init>(ConnectionManager.java:604)
	... 13 more
2015-03-21 02:11:06,971 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(946): Stopping infoServer
2015-03-21 02:11:06,969 ERROR [RS:0;proserpina:51019] regionserver.HRegionServer(2863): Failed init
java.io.IOException: java.lang.reflect.InvocationTargetException
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:239)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:217)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:118)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSink.<init>(ReplicationSink.java:90)
	at org.apache.hadoop.hbase.replication.regionserver.Replication.startReplicationService(Replication.java:213)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.startServiceThreads(HRegionServer.java:1684)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.handleReportForDutyResponse(HRegionServer.java:1323)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.handleReportForDutyResponse(MiniHBaseCluster.java:129)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:874)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.runRegionServer(MiniHBaseCluster.java:155)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.access$000(MiniHBaseCluster.java:107)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer$1.run(MiniHBaseCluster.java:139)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:356)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1594)
	at org.apache.hadoop.hbase.security.User$SecureHadoopUser.runAs(User.java:304)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.run(MiniHBaseCluster.java:137)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:237)
	... 17 more
Caused by: java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method)
	at java.lang.Thread.start(Thread.java:713)
	at org.apache.zookeeper.ClientCnxn.start(ClientCnxn.java:405)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:450)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:380)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.checkZk(RecoverableZooKeeper.java:142)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.<init>(RecoverableZooKeeper.java:129)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.connect(ZKUtil.java:155)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:163)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:131)
	at org.apache.hadoop.hbase.client.ZooKeeperKeepAliveConnection.<init>(ZooKeeperKeepAliveConnection.java:43)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.getKeepAliveZooKeeperWatcher(ConnectionManager.java:1617)
	at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:101)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.retrieveClusterId(ConnectionManager.java:844)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.<init>(ConnectionManager.java:604)
	... 22 more
2015-03-21 02:11:06,980 FATAL [RS:0;proserpina:51019] regionserver.HRegionServer(1994): ABORTING region server proserpina.apache.org,51019,1426903864687: Unhandled: java.lang.reflect.InvocationTargetException
java.io.IOException: java.lang.reflect.InvocationTargetException
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:239)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:217)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:118)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSink.<init>(ReplicationSink.java:90)
	at org.apache.hadoop.hbase.replication.regionserver.Replication.startReplicationService(Replication.java:213)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.startServiceThreads(HRegionServer.java:1684)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.handleReportForDutyResponse(HRegionServer.java:1323)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.handleReportForDutyResponse(MiniHBaseCluster.java:129)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:874)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.runRegionServer(MiniHBaseCluster.java:155)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.access$000(MiniHBaseCluster.java:107)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer$1.run(MiniHBaseCluster.java:139)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:356)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1594)
	at org.apache.hadoop.hbase.security.User$SecureHadoopUser.runAs(User.java:304)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.run(MiniHBaseCluster.java:137)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:237)
	... 17 more
Caused by: java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method)
	at java.lang.Thread.start(Thread.java:713)
	at org.apache.zookeeper.ClientCnxn.start(ClientCnxn.java:405)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:450)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:380)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.checkZk(RecoverableZooKeeper.java:142)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.<init>(RecoverableZooKeeper.java:129)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.connect(ZKUtil.java:155)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:163)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:131)
	at org.apache.hadoop.hbase.client.ZooKeeperKeepAliveConnection.<init>(ZooKeeperKeepAliveConnection.java:43)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.getKeepAliveZooKeeperWatcher(ConnectionManager.java:1617)
	at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:101)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.retrieveClusterId(ConnectionManager.java:844)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.<init>(ConnectionManager.java:604)
	... 22 more
2015-03-21 02:11:06,993 FATAL [RS:0;proserpina:51019] regionserver.HRegionServer(2002): RegionServer abort: loaded coprocessors are: [org.apache.hadoop.hbase.security.access.SecureTestUtil$MasterSyncObserver, org.apache.hadoop.hbase.security.access.AccessController]
2015-03-21 02:11:06,996 INFO  [M:0;proserpina:38530] log.Slf4jLog(67): Stopped SelectChannelConnector@0.0.0.0:0
2015-03-21 02:11:07,000 INFO  [MemStoreFlusher.0] regionserver.MemStoreFlusher$FlushHandler(281): MemStoreFlusher.0 exiting
2015-03-21 02:11:07,001 INFO  [MemStoreFlusher.1] regionserver.MemStoreFlusher$FlushHandler(281): MemStoreFlusher.1 exiting
2015-03-21 02:11:07,000 INFO  [M:0;proserpina:38530] snapshot.RegionServerSnapshotManager(134): Stopping RegionServerSnapshotManager gracefully.
2015-03-21 02:11:07,001 INFO  [M:0;proserpina:38530] flush.RegionServerFlushTableProcedureManager(113): Stopping region server flush procedure manager gracefully.
2015-03-21 02:11:07,002 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(991): stopping server proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:07,002 DEBUG [M:0;proserpina:38530] zookeeper.MetaTableLocator(617): Stopping MetaTableLocator
2015-03-21 02:11:07,002 INFO  [M:0;proserpina:38530] client.ConnectionManager$HConnectionImplementation(1637): Closing zookeeper sessionid=0x14c3a1908520003
2015-03-21 02:11:07,028 DEBUG [M:0;proserpina:38530] ipc.AsyncRpcClient(288): Stopping async HBase RPC client
2015-03-21 02:11:07,030 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(1019): stopping server proserpina.apache.org,38530,1426903862856; all regions closed.
2015-03-21 02:11:07,030 DEBUG [M:0;proserpina:38530] wal.FSHLog(1147): Closing WAL writer in /user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:07,041 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(2006): Dump of metrics as JSON on abort: {
  "beans" : [ {
    "name" : "java.lang:type=Memory",
    "modelerType" : "sun.management.MemoryImpl",
    "NonHeapMemoryUsage" : {
      "committed" : 54984704,
      "init" : 24576000,
      "max" : 318767104,
      "used" : 54064320
    },
    "ObjectPendingFinalizationCount" : 0,
    "Verbose" : false,
    "HeapMemoryUsage" : {
      "committed" : 957349888,
      "init" : 791251328,
      "max" : 2609905664,
      "used" : 318592544
    },
    "ObjectName" : "java.lang:type=Memory"
  } ],
  "beans" : [ {
    "name" : "Hadoop:service=HBase,name=RegionServer,sub=IPC",
    "modelerType" : "RegionServer,sub=IPC",
    "tag.Context" : "regionserver",
    "tag.Hostname" : "proserpina.apache.org",
    "queueSize" : 0,
    "numCallsInGeneralQueue" : 0,
    "numCallsInReplicationQueue" : 0,
    "numCallsInPriorityQueue" : 0,
    "numOpenConnections" : 0,
    "numActiveHandler" : 0,
    "QueueCallTime_num_ops" : 0,
    "QueueCallTime_min" : 0,
    "QueueCallTime_max" : 0,
    "QueueCallTime_mean" : 0.0,
    "QueueCallTime_median" : 0.0,
    "QueueCallTime_75th_percentile" : 0.0,
    "QueueCallTime_95th_percentile" : 0.0,
    "QueueCallTime_99th_percentile" : 0.0,
    "authenticationFailures" : 0,
    "authorizationFailures" : 0,
    "authenticationSuccesses" : 0,
    "authorizationSuccesses" : 0,
    "ProcessCallTime_num_ops" : 0,
    "ProcessCallTime_min" : 0,
    "ProcessCallTime_max" : 0,
    "ProcessCallTime_mean" : 0.0,
    "ProcessCallTime_median" : 0.0,
    "ProcessCallTime_75th_percentile" : 0.0,
    "ProcessCallTime_95th_percentile" : 0.0,
    "ProcessCallTime_99th_percentile" : 0.0,
    "sentBytes" : 0,
    "receivedBytes" : 0
  } ],
  "beans" : [ {
    "name" : "Hadoop:service=HBase,name=RegionServer,sub=Replication",
    "modelerType" : "RegionServer,sub=Replication",
    "tag.Context" : "regionserver",
    "tag.Hostname" : "proserpina.apache.org",
    "sink.appliedOps" : 0,
    "sink.appliedBatches" : 0,
    "sink.ageOfLastAppliedOp" : 0
  } ],
  "beans" : [ {
    "name" : "Hadoop:service=HBase,name=RegionServer,sub=Server",
    "modelerType" : "RegionServer,sub=Server",
    "tag.zookeeperQuorum" : "localhost:55239",
    "tag.serverName" : "proserpina.apache.org,38530,1426903862856",
    "tag.clusterId" : "9500695b-0220-487d-9d12-037e9eed7bc7",
    "tag.Context" : "regionserver",
    "tag.Hostname" : "proserpina.apache.org",
    "regionCount" : 0,
    "storeCount" : 0,
    "hlogFileCount" : 0,
    "hlogFileSize" : 0,
    "storeFileCount" : 0,
    "memStoreSize" : 0,
    "storeFileSize" : 0,
    "regionServerStartTime" : 1426903862856,
    "totalRequestCount" : 0,
    "readRequestCount" : 0,
    "writeRequestCount" : 0,
    "checkMutateFailedCount" : 0,
    "checkMutatePassedCount" : 0,
    "storeFileIndexSize" : 0,
    "staticIndexSize" : 0,
    "staticBloomSize" : 0,
    "mutationsWithoutWALCount" : 0,
    "mutationsWithoutWALSize" : 0,
    "percentFilesLocal" : 0,
    "splitQueueLength" : 0,
    "compactionQueueLength" : 0,
    "flushQueueLength" : 0,
    "blockCacheFreeSize" : 1042890544,
    "blockCacheCount" : 0,
    "blockCacheSize" : 1071760,
    "blockCacheHitCount" : 0,
    "blockCacheMissCount" : 0,
    "blockCacheEvictionCount" : 0,
    "blockCacheCountHitPercent" : 0.0,
    "blockCacheExpressHitPercent" : 0,
    "updatesBlockedTime" : 0,
    "flushedCellsCount" : 0,
    "compactedCellsCount" : 0,
    "majorCompactedCellsCount" : 0,
    "flushedCellsSize" : 0,
    "compactedCellsSize" : 0,
    "majorCompactedCellsSize" : 0,
    "hedgedReads" : 0,
    "hedgedReadWins" : 0,
    "blockedRequestCount" : 0,
    "Append_num_ops" : 0,
    "Append_min" : 0,
    "Append_max" : 0,
    "Append_mean" : 0.0,
    "Append_median" : 0.0,
    "Append_75th_percentile" : 0.0,
    "Append_95th_percentile" : 0.0,
    "Append_99th_percentile" : 0.0,
    "splitSuccessCounnt" : 0,
    "Delete_num_ops" : 0,
    "Delete_min" : 0,
    "Delete_max" : 0,
    "Delete_mean" : 0.0,
    "Delete_median" : 0.0,
    "Delete_75th_percentile" : 0.0,
    "Delete_95th_percentile" : 0.0,
    "Delete_99th_percentile" : 0.0,
    "Mutate_num_ops" : 0,
    "Mutate_min" : 0,
    "Mutate_max" : 0,
    "Mutate_mean" : 0.0,
    "Mutate_median" : 0.0,
    "Mutate_75th_percentile" : 0.0,
    "Mutate_95th_percentile" : 0.0,
    "Mutate_99th_percentile" : 0.0,
    "slowDeleteCount" : 0,
    "splitRequestCount" : 0,
    "slowIncrementCount" : 0,
    "FlushTime_num_ops" : 0,
    "FlushTime_min" : 0,
    "FlushTime_max" : 0,
    "FlushTime_mean" : 0.0,
    "FlushTime_median" : 0.0,
    "FlushTime_75th_percentile" : 0.0,
    "FlushTime_95th_percentile" : 0.0,
    "FlushTime_99th_percentile" : 0.0,
    "Get_num_ops" : 0,
    "Get_min" : 0,
    "Get_max" : 0,
    "Get_mean" : 0.0,
    "Get_median" : 0.0,
    "Get_75th_percentile" : 0.0,
    "Get_95th_percentile" : 0.0,
    "Get_99th_percentile" : 0.0,
    "Replay_num_ops" : 0,
    "Replay_min" : 0,
    "Replay_max" : 0,
    "Replay_mean" : 0.0,
    "Replay_median" : 0.0,
    "Replay_75th_percentile" : 0.0,
    "Replay_95th_percentile" : 0.0,
    "Replay_99th_percentile" : 0.0,
    "slowGetCount" : 0,
    "slowAppendCount" : 0,
    "slowPutCount" : 0,
    "SplitTime_num_ops" : 0,
    "SplitTime_min" : 0,
    "SplitTime_max" : 0,
    "SplitTime_mean" : 0.0,
    "SplitTime_median" : 0.0,
    "SplitTime_75th_percentile" : 0.0,
    "SplitTime_95th_percentile" : 0.0,
    "SplitTime_99th_percentile" : 0.0,
    "Increment_num_ops" : 0,
    "Increment_min" : 0,
    "Increment_max" : 0,
    "Increment_mean" : 0.0,
    "Increment_median" : 0.0,
    "Increment_75th_percentile" : 0.0,
    "Increment_95th_percentile" : 0.0,
    "Increment_99th_percentile" : 0.0
  } ]
}
2015-03-21 02:11:07,046 INFO  [IPC Server handler 9 on 42912] blockmanagement.BlockManager(2383): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:54374 is added to blk_1073741829_1005{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-20704df4-ae22-40c7-8dcd-b411672f6980:NORMAL|RBW]]} size 83
2015-03-21 02:11:07,068 ERROR [B.defaultRpcServer.handler=3,queue=0,port=38530] master.MasterRpcServices(328): Region server proserpina.apache.org,51019,1426903864687 reported a fatal error:
ABORTING region server proserpina.apache.org,51019,1426903864687: Unhandled: java.lang.reflect.InvocationTargetException
Cause:
java.io.IOException: java.lang.reflect.InvocationTargetException
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:239)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:217)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:118)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSink.<init>(ReplicationSink.java:90)
	at org.apache.hadoop.hbase.replication.regionserver.Replication.startReplicationService(Replication.java:213)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.startServiceThreads(HRegionServer.java:1684)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.handleReportForDutyResponse(HRegionServer.java:1323)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.handleReportForDutyResponse(MiniHBaseCluster.java:129)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:874)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.runRegionServer(MiniHBaseCluster.java:155)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.access$000(MiniHBaseCluster.java:107)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer$1.run(MiniHBaseCluster.java:139)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:356)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1594)
	at org.apache.hadoop.hbase.security.User$SecureHadoopUser.runAs(User.java:304)
	at org.apache.hadoop.hbase.MiniHBaseCluster$MiniHBaseClusterRegionServer.run(MiniHBaseCluster.java:137)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
	at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:237)
	... 17 more
Caused by: java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method)
	at java.lang.Thread.start(Thread.java:713)
	at org.apache.zookeeper.ClientCnxn.start(ClientCnxn.java:405)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:450)
	at org.apache.zookeeper.ZooKeeper.<init>(ZooKeeper.java:380)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.checkZk(RecoverableZooKeeper.java:142)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.<init>(RecoverableZooKeeper.java:129)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.connect(ZKUtil.java:155)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:163)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.<init>(ZooKeeperWatcher.java:131)
	at org.apache.hadoop.hbase.client.ZooKeeperKeepAliveConnection.<init>(ZooKeeperKeepAliveConnection.java:43)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.getKeepAliveZooKeeperWatcher(ConnectionManager.java:1617)
	at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:101)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.retrieveClusterId(ConnectionManager.java:844)
	at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.<init>(ConnectionManager.java:604)
	... 22 more

2015-03-21 02:11:07,072 DEBUG [M:0;proserpina:38530] wal.FSHLog(1105): Moved 1 WAL file(s) to /user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/oldWALs
2015-03-21 02:11:07,072 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(946): Stopping infoServer
2015-03-21 02:11:07,072 INFO  [M:0;proserpina:38530] wal.FSHLog(1108): Closed WAL: FSHLog proserpina.apache.org%2C38530%2C1426903862856.default:(num 1426903866643)
2015-03-21 02:11:07,073 DEBUG [M:0;proserpina:38530] ipc.AsyncRpcClient(288): Stopping async HBase RPC client
2015-03-21 02:11:07,078 INFO  [M:0;proserpina:38530] regionserver.Leases(146): M:0;proserpina:38530 closing leases
2015-03-21 02:11:07,079 INFO  [M:0;proserpina:38530] regionserver.Leases(149): M:0;proserpina:38530 closed leases
2015-03-21 02:11:07,083 INFO  [M:0;proserpina:38530] hbase.ChoreService(303): Chore service for: proserpina.apache.org,38530,1426903862856 had [java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@16af619d, java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@5431960d, java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3725aaa, java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@489e50aa, java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@11c1ee25] on shutdown
2015-03-21 02:11:07,089 INFO  [RS:0;proserpina:51019] log.Slf4jLog(67): Stopped SelectChannelConnector@0.0.0.0:0
2015-03-21 02:11:07,195 INFO  [MemStoreFlusher.1] regionserver.MemStoreFlusher$FlushHandler(281): MemStoreFlusher.1 exiting
2015-03-21 02:11:07,195 INFO  [MemStoreFlusher.0] regionserver.MemStoreFlusher$FlushHandler(281): MemStoreFlusher.0 exiting
2015-03-21 02:11:07,195 INFO  [RS:0;proserpina:51019] snapshot.RegionServerSnapshotManager(134): Stopping RegionServerSnapshotManager abruptly.
2015-03-21 02:11:07,196 INFO  [RS:0;proserpina:51019] flush.RegionServerFlushTableProcedureManager(113): Stopping region server flush procedure manager abruptly.
2015-03-21 02:11:07,196 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(988): aborting server proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:07,196 DEBUG [RS:0;proserpina:51019] zookeeper.MetaTableLocator(617): Stopping MetaTableLocator
2015-03-21 02:11:07,197 INFO  [RS:0;proserpina:51019] client.ConnectionManager$HConnectionImplementation(1637): Closing zookeeper sessionid=0x14c3a1908520002
2015-03-21 02:11:07,247 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(288): Stopping async HBase RPC client
2015-03-21 02:11:07,248 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(1019): stopping server proserpina.apache.org,51019,1426903864687; all regions closed.
2015-03-21 02:11:07,248 DEBUG [RS:0;proserpina:51019] wal.FSHLog(1147): Closing WAL writer in /user/jenkins/test-data/94a25112-a109-49f6-9edd-039180512bc6/WALs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:07,273 INFO  [IPC Server handler 4 on 42912] blockmanagement.BlockManager(2383): BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:54374 is added to blk_1073741830_1006{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a2d75141-06d2-4e32-a0f7-999efc9c94fc:NORMAL|RBW]]} size 83
2015-03-21 02:11:07,279 DEBUG [RS:0;proserpina:51019] ipc.AsyncRpcClient(288): Stopping async HBase RPC client
2015-03-21 02:11:07,281 INFO  [RS:0;proserpina:51019] regionserver.Leases(146): RS:0;proserpina:51019 closing leases
2015-03-21 02:11:07,281 INFO  [RS:0;proserpina:51019] regionserver.Leases(149): RS:0;proserpina:51019 closed leases
2015-03-21 02:11:07,282 INFO  [RS:0;proserpina:51019] hbase.ChoreService(303): Chore service for: proserpina.apache.org,51019,1426903864687 had [java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@47ce7f8f, java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@20ac9761, java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@23067209] on shutdown
2015-03-21 02:11:07,285 DEBUG [RpcServer.reader=1,bindAddress=proserpina.apache.org,port=38530] ipc.RpcServer$Listener(841): RpcServer.listener,port=38530: DISCONNECTING client 67.195.81.189:42362 because read count=-1. Number of active connections: 1
2015-03-21 02:11:07,286 DEBUG [AsyncRpcChannel-pool2-t1] ipc.AsyncRpcChannel$8(574): IPC Client (-1955567686) connection to proserpina.apache.org/67.195.81.189:38530 from jenkins.hfs.0: closed
2015-03-21 02:11:07,737 INFO  [proserpina.apache.org,38530,1426903862856_splitLogManager__ChoreService_1] hbase.ScheduledChore(179): Chore: SplitLogManager Timeout Monitor was stopped
2015-03-21 02:11:07,840 INFO  [master/proserpina.apache.org/67.195.81.189:0.logRoller] regionserver.LogRoller(159): LogRoller exiting.
2015-03-21 02:11:07,841 INFO  [M:0;proserpina:38530] regionserver.CompactSplitThread(393): Waiting for Split Thread to finish...
2015-03-21 02:11:07,841 INFO  [M:0;proserpina:38530] regionserver.CompactSplitThread(393): Waiting for Merge Thread to finish...
2015-03-21 02:11:07,841 INFO  [M:0;proserpina:38530] regionserver.CompactSplitThread(393): Waiting for Large Compaction Thread to finish...
2015-03-21 02:11:07,841 INFO  [M:0;proserpina:38530] regionserver.CompactSplitThread(393): Waiting for Small Compaction Thread to finish...
2015-03-21 02:11:07,847 INFO  [master/proserpina.apache.org/67.195.81.189:0.leaseChecker] regionserver.Leases(146): master/proserpina.apache.org/67.195.81.189:0.leaseChecker closing leases
2015-03-21 02:11:07,847 INFO  [master/proserpina.apache.org/67.195.81.189:0.leaseChecker] regionserver.Leases(149): master/proserpina.apache.org/67.195.81.189:0.leaseChecker closed leases
2015-03-21 02:11:07,853 DEBUG [M:0;proserpina:38530] master.HMaster(1045): Stopping service threads
2015-03-21 02:11:07,853 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/replication/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:07,864 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/master
2015-03-21 02:11:07,866 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/master
2015-03-21 02:11:07,866 INFO  [M:0;proserpina:38530] client.ConnectionManager$HConnectionImplementation(1637): Closing zookeeper sessionid=0x14c3a1908520004
2015-03-21 02:11:07,867 DEBUG [main-EventThread] zookeeper.ZKUtil(488): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/master
2015-03-21 02:11:07,867 DEBUG [main-EventThread] zookeeper.ZKUtil(488): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Set watcher on znode that does not yet exist, /hbase/master
2015-03-21 02:11:07,872 DEBUG [M:0;proserpina:38530] ipc.AsyncRpcClient(288): Stopping async HBase RPC client
2015-03-21 02:11:07,873 INFO  [M:0;proserpina:38530] hbase.ChoreService(303): Chore service for: proserpina.apache.org,38530,1426903862856_splitLogManager_ had [] on shutdown
2015-03-21 02:11:07,874 INFO  [M:0;proserpina:38530] flush.MasterFlushTableProcedureManager(78): stop: server shutting down.
2015-03-21 02:11:07,875 INFO  [M:0;proserpina:38530] ipc.RpcServer(2169): Stopping server on 38530
2015-03-21 02:11:07,876 INFO  [RpcServer.listener,port=38530] ipc.RpcServer$Listener(745): RpcServer.listener,port=38530: stopping
2015-03-21 02:11:07,876 INFO  [RpcServer.responder] ipc.RpcServer$Responder(987): RpcServer.responder: stopped
2015-03-21 02:11:07,876 INFO  [RpcServer.responder] ipc.RpcServer$Responder(890): RpcServer.responder: stopping
2015-03-21 02:11:07,891 INFO  [regionserver/proserpina.apache.org/67.195.81.189:0.leaseChecker] regionserver.Leases(146): regionserver/proserpina.apache.org/67.195.81.189:0.leaseChecker closing leases
2015-03-21 02:11:07,892 INFO  [regionserver/proserpina.apache.org/67.195.81.189:0.leaseChecker] regionserver.Leases(149): regionserver/proserpina.apache.org/67.195.81.189:0.leaseChecker closed leases
2015-03-21 02:11:07,891 INFO  [regionserver/proserpina.apache.org/67.195.81.189:0.logRoller] regionserver.LogRoller(159): LogRoller exiting.
2015-03-21 02:11:07,893 INFO  [RS:0;proserpina:51019] regionserver.CompactSplitThread(393): Waiting for Split Thread to finish...
2015-03-21 02:11:07,893 INFO  [RS:0;proserpina:51019] regionserver.CompactSplitThread(393): Waiting for Merge Thread to finish...
2015-03-21 02:11:07,893 INFO  [RS:0;proserpina:51019] regionserver.CompactSplitThread(393): Waiting for Large Compaction Thread to finish...
2015-03-21 02:11:07,893 INFO  [RS:0;proserpina:51019] regionserver.CompactSplitThread(393): Waiting for Small Compaction Thread to finish...
2015-03-21 02:11:07,897 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:07,898 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/rs/proserpina.apache.org,38530,1426903862856
2015-03-21 02:11:07,898 INFO  [main-EventThread] zookeeper.RegionServerTracker(118): RegionServer ephemeral node deleted, processing expiration [proserpina.apache.org,38530,1426903862856]
2015-03-21 02:11:07,898 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/rs
2015-03-21 02:11:07,898 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): master:38530-0x14c3a1908520000, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/rs
2015-03-21 02:11:07,906 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(1063): stopping server proserpina.apache.org,38530,1426903862856; zookeeper connection closed.
2015-03-21 02:11:07,906 INFO  [M:0;proserpina:38530] regionserver.HRegionServer(1066): M:0;proserpina:38530 exiting
2015-03-21 02:11:07,923 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/replication/rs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:07,923 INFO  [RS:0;proserpina:51019] ipc.RpcServer(2169): Stopping server on 51019
2015-03-21 02:11:07,924 INFO  [RpcServer.responder] ipc.RpcServer$Responder(987): RpcServer.responder: stopped
2015-03-21 02:11:07,925 INFO  [RpcServer.responder] ipc.RpcServer$Responder(890): RpcServer.responder: stopping
2015-03-21 02:11:07,928 INFO  [RpcServer.listener,port=51019] ipc.RpcServer$Listener(745): RpcServer.listener,port=51019: stopping
2015-03-21 02:11:07,936 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(388): regionserver:51019-0x14c3a1908520001, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/rs/proserpina.apache.org,51019,1426903864687
2015-03-21 02:11:07,952 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(1063): stopping server proserpina.apache.org,51019,1426903864687; zookeeper connection closed.
2015-03-21 02:11:07,954 INFO  [RS:0;proserpina:51019] regionserver.HRegionServer(1066): RS:0;proserpina:51019 exiting
2015-03-21 02:14:25,110 ERROR [main] hbase.MiniHBaseCluster(229): Error starting cluster
java.lang.RuntimeException: Master not initialized after 200000ms seconds
	at org.apache.hadoop.hbase.util.JVMClusterUtil.startup(JVMClusterUtil.java:225)
	at org.apache.hadoop.hbase.LocalHBaseCluster.startup(LocalHBaseCluster.java:437)
	at org.apache.hadoop.hbase.MiniHBaseCluster.init(MiniHBaseCluster.java:224)
	at org.apache.hadoop.hbase.MiniHBaseCluster.<init>(MiniHBaseCluster.java:93)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:1008)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:968)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:842)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:836)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:780)
	at org.apache.hadoop.hbase.security.access.TestAccessController.setupBeforeClass(TestAccessController.java:191)
	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.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runners.Suite.runChild(Suite.java:127)
	at org.junit.runners.Suite.runChild(Suite.java:26)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:107)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:77)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:53)
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:144)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:203)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:155)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
2015-03-21 02:14:25,112 DEBUG [main] util.JVMClusterUtil(241): Shutting down HBase Cluster
2015-03-21 02:14:25,113 DEBUG [main] coprocessor.CoprocessorHost(269): Stop coprocessor org.apache.hadoop.hbase.security.access.AccessController
2015-03-21 02:14:25,113 DEBUG [main] coprocessor.CoprocessorHost(269): Stop coprocessor org.apache.hadoop.hbase.security.access.SecureTestUtil$MasterSyncObserver
2015-03-21 02:14:25,115 WARN  [main] zookeeper.RecoverableZooKeeper(276): Possibly transient ZooKeeper, quorum=localhost:55239, exception=org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /hbase/running
2015-03-21 02:14:26,115 WARN  [main] zookeeper.RecoverableZooKeeper(276): Possibly transient ZooKeeper, quorum=localhost:55239, exception=org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /hbase/running
2015-03-21 02:14:28,116 WARN  [main] zookeeper.RecoverableZooKeeper(276): Possibly transient ZooKeeper, quorum=localhost:55239, exception=org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /hbase/running
2015-03-21 02:14:32,119 WARN  [main] zookeeper.RecoverableZooKeeper(276): Possibly transient ZooKeeper, quorum=localhost:55239, exception=org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /hbase/running
2015-03-21 02:14:40,122 WARN  [main] zookeeper.RecoverableZooKeeper(276): Possibly transient ZooKeeper, quorum=localhost:55239, exception=org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /hbase/running
2015-03-21 02:14:40,126 ERROR [main] zookeeper.RecoverableZooKeeper(278): ZooKeeper delete failed after 4 attempts
2015-03-21 02:14:40,126 ERROR [main] master.HMaster(1877): ZooKeeper exception trying to set cluster as down in ZK
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /hbase/running
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
	at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.delete(RecoverableZooKeeper.java:179)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.deleteNode(ZKUtil.java:1341)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.deleteNode(ZKUtil.java:1330)
	at org.apache.hadoop.hbase.zookeeper.ClusterStatusTracker.setClusterDown(ClusterStatusTracker.java:82)
	at org.apache.hadoop.hbase.master.HMaster.shutdown(HMaster.java:1875)
	at org.apache.hadoop.hbase.util.JVMClusterUtil.shutdown(JVMClusterUtil.java:254)
	at org.apache.hadoop.hbase.LocalHBaseCluster.shutdown(LocalHBaseCluster.java:444)
	at org.apache.hadoop.hbase.MiniHBaseCluster.shutdown(MiniHBaseCluster.java:517)
	at org.apache.hadoop.hbase.MiniHBaseCluster.init(MiniHBaseCluster.java:230)
	at org.apache.hadoop.hbase.MiniHBaseCluster.<init>(MiniHBaseCluster.java:93)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster(HBaseTestingUtility.java:1008)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:968)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:842)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:836)
	at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster(HBaseTestingUtility.java:780)
	at org.apache.hadoop.hbase.security.access.TestAccessController.setupBeforeClass(TestAccessController.java:191)
	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.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runners.Suite.runChild(Suite.java:127)
	at org.junit.runners.Suite.runChild(Suite.java:26)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:107)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:77)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:53)
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:144)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:203)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:155)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
2015-03-21 02:14:40,129 INFO  [main] util.JVMClusterUtil(317): Shutdown of 1 master(s) and 1 regionserver(s) complete
2015-03-21 02:14:40,129 INFO  [main] hbase.HBaseTestingUtility(1068): Shutting down minicluster
2015-03-21 02:14:40,135 INFO  [main] zookeeper.MiniZooKeeperCluster(319): Shutdown MiniZK cluster with all ZK servers
2015-03-21 02:14:40,136 WARN  [main] datanode.DirectoryScanner(375): DirectoryScanner: shutdown has been called
2015-03-21 02:14:40,154 INFO  [main] log.Slf4jLog(67): Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
2015-03-21 02:14:40,232 DEBUG [proserpina:38530.activeMasterManager-EventThread] zookeeper.ZooKeeperWatcher(388): replicationLogCleaner-0x14c3a1908520005, quorum=localhost:55239, baseZNode=/hbase Received ZooKeeper Event, type=None, state=Disconnected, path=null
2015-03-21 02:14:40,232 DEBUG [proserpina:38530.activeMasterManager-EventThread] zookeeper.ZooKeeperWatcher(477): replicationLogCleaner-0x14c3a1908520005, quorum=localhost:55239, baseZNode=/hbase Received Disconnected from ZooKeeper, ignoring
2015-03-21 02:14:40,258 WARN  [DataNode: [[[DISK]file:/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data1/, [DISK]file:/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data2/]]  heartbeating to localhost/127.0.0.1:42912] datanode.BPServiceActor(722): BPOfferService for Block pool BP-27234177-67.195.81.189-1426903856367 (Datanode Uuid bf0194c5-f830-4a3c-a9e4-a3e5516d3196) service to localhost/127.0.0.1:42912 interrupted
2015-03-21 02:14:40,259 WARN  [DataNode: [[[DISK]file:/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data1/, [DISK]file:/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-server/target/test-data/5d031ef7-820c-47c8-9f14-20a54526f48a/dfscluster_d80b1d01-c629-432f-832e-eb812b7810fa/dfs/data/data2/]]  heartbeating to localhost/127.0.0.1:42912] datanode.BPServiceActor(845): Ending block pool service for: Block pool BP-27234177-67.195.81.189-1426903856367 (Datanode Uuid bf0194c5-f830-4a3c-a9e4-a3e5516d3196) service to localhost/127.0.0.1:42912
2015-03-21 02:14:40,297 WARN  [org.apache.hadoop.hdfs.server.blockmanagement.DecommissionManager$Monitor@10c8414a] blockmanagement.DecommissionManager$Monitor(78): Monitor interrupted: java.lang.InterruptedException: sleep interrupted
2015-03-21 02:14:40,353 INFO  [main] log.Slf4jLog(67): Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
2015-03-21 02:14:40,547 INFO  [main] hbase.HBaseTestingUtility(1081): Minicluster is down
{code}


> Fix the critical ancient loopholes in security testing infrastructure.
> ----------------------------------------------------------------------
>
>                 Key: HBASE-13294
>                 URL: https://issues.apache.org/jira/browse/HBASE-13294
>             Project: HBase
>          Issue Type: Bug
>            Reporter: Srikanth Srungarapu
>            Assignee: Srikanth Srungarapu
>         Attachments: HBASE-13294.patch, HBASE-13294_v2.patch, HBASE-13294_v3.patch, HBASE-13294_v3.patch, HBASE-13294_v4.patch
>
>
> Unfortunately, the "verifyDenied" method doesn't fail when action parameter returns null. The relevant code snippet
> {code}
> try {
>         Object obj = user.runAs(action);
>         if (requireException) {
>           fail("Expected exception was not thrown for user '" + user.getShortName() + "'");
>         }
>         if (obj != null && obj instanceof List<?>) {
>           List<?> results = (List<?>) obj;
>           if (results != null && !results.isEmpty()) {
>             fail("Unexpected results for user '" + user.getShortName() + "'");
>           }
>         }
>       }
> {code}
> As you can see, when obj is null, it returns silently. 
> Fixing this issue has uncovered another major bug. While constructing actions, we're using TEST_UTIL.getConnection(), which replaces the "doAs" user with the user who initiated the connection. I really am grateful to [~mbertozzi] without whom debugging this would have been a nightmare. 
> Now, fixing these two issues have uncovered more issues in our tests :). The main one is we're allowing the table owner to truncate table in code. But, in test, we're not allowing him. We should either remove the code that allows owner or document that the table owner can truncate table.
> The other minor issues include granting permissions to namespace, but checking whether user was able to access tables inside other namespace.  
> That's it, folks! 



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message