2017-01-25 21:22:57,124 INFO [RS_OPEN_META-sandbox:16020-0] coprocessor.CoprocessorHost: System coprocessor org.apache.ranger.authorization.hbase.RangerAuthorizationCoprocessor was loaded successfully with priority (536870911). 2017-01-25 21:22:57,151 INFO [RS_OPEN_META-sandbox:16020-0] regionserver.RegionCoprocessorHost: Loaded coprocessor org.apache.hadoop.hbase.coprocessor.MultiRowMutationEndpoint from HTD of hbase:meta successfully. 2017-01-25 21:22:57,253 INFO [StoreOpener-1588230740-1] hfile.CacheConfig: blockCache=LruBlockCache{blockCount=0, currentSize=433080, freeSize=420675048, maxSize=421108128, heapSize=433080, minSize=400052704, minFactor=0.95, multiSize=200026352, multiFactor=0.5, singleSize=100013176, singleFactor=0.25}, cacheDataOnRead=true, cacheDataOnWrite=false, cacheIndexesOnWrite=false, cacheBloomsOnWrite=false, cacheEvictOnClose=false, cacheDataCompressed=false, prefetchOnOpen=false 2017-01-25 21:22:57,268 INFO [StoreOpener-1588230740-1] compactions.CompactionConfiguration: 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 2017-01-25 21:22:57,314 INFO [RS_OPEN_META-sandbox:16020-0-MetaLogRoller] regionserver.LogRoller: LogRoller exiting. 2017-01-25 21:22:57,315 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] regionserver.CompactSplitThread: Waiting for Split Thread to finish... 2017-01-25 21:22:57,316 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] regionserver.CompactSplitThread: Waiting for Merge Thread to finish... 2017-01-25 21:22:57,316 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] regionserver.CompactSplitThread: Waiting for Large Compaction Thread to finish... 2017-01-25 21:22:57,316 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] regionserver.CompactSplitThread: Waiting for Small Compaction Thread to finish... 2017-01-25 21:22:57,331 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] ipc.RpcServer: Stopping server on 16020 2017-01-25 21:22:57,331 INFO [RpcServer.listener,port=16020] ipc.RpcServer: RpcServer.listener,port=16020: stopping 2017-01-25 21:22:57,337 INFO [RpcServer.responder] ipc.RpcServer: RpcServer.responder: stopped 2017-01-25 21:22:57,337 INFO [RpcServer.responder] ipc.RpcServer: RpcServer.responder: stopping 2017-01-25 21:22:57,417 WARN [RS_OPEN_META-sandbox:16020-0] ipc.Client: interrupted waiting to send rpc request to server java.lang.InterruptedException at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:400) at java.util.concurrent.FutureTask.get(FutureTask.java:187) at org.apache.hadoop.ipc.Client$Connection.sendRpcRequest(Client.java:1057) at org.apache.hadoop.ipc.Client.call(Client.java:1400) at org.apache.hadoop.ipc.Client.call(Client.java:1358) at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:229) at com.sun.proxy.$Proxy15.getFileInfo(Unknown Source) at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getFileInfo(ClientNamenodeProtocolTranslatorPB.java:771) at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:252) at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:104) at com.sun.proxy.$Proxy16.getFileInfo(Unknown Source) at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.apache.hadoop.hbase.fs.HFileSystem$1.invoke(HFileSystem.java:279) at com.sun.proxy.$Proxy17.getFileInfo(Unknown Source) at org.apache.hadoop.hdfs.DFSClient.getFileInfo(DFSClient.java:2116) at org.apache.hadoop.hdfs.DistributedFileSystem$22.doCall(DistributedFileSystem.java:1315) at org.apache.hadoop.hdfs.DistributedFileSystem$22.doCall(DistributedFileSystem.java:1311) at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81) at org.apache.hadoop.hdfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:1311) at org.apache.hadoop.fs.FilterFileSystem.getFileStatus(FilterFileSystem.java:421) at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:1424) at org.apache.hadoop.fs.FileSystem.createNewFile(FileSystem.java:1149) at org.apache.hadoop.hbase.wal.WALSplitter.writeRegionSequenceIdFile(WALSplitter.java:716) at org.apache.hadoop.hbase.regionserver.HRegion.initializeRegionInternals(HRegion.java:860) at org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:794) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6328) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6289) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6260) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6216) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6167) at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:362) at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:129) at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2017-01-25 21:22:57,418 ERROR [RS_OPEN_META-sandbox:16020-0] handler.OpenRegionHandler: Failed open of region=hbase:meta,,1.1588230740, starting to roll back the global memstore size. java.io.IOException: java.lang.InterruptedException at org.apache.hadoop.ipc.Client.call(Client.java:1406) at org.apache.hadoop.ipc.Client.call(Client.java:1358) at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:229) at com.sun.proxy.$Proxy15.getFileInfo(Unknown Source) at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getFileInfo(ClientNamenodeProtocolTranslatorPB.java:771) at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:252) at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:104) at com.sun.proxy.$Proxy16.getFileInfo(Unknown Source) at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.apache.hadoop.hbase.fs.HFileSystem$1.invoke(HFileSystem.java:279) at com.sun.proxy.$Proxy17.getFileInfo(Unknown Source) at org.apache.hadoop.hdfs.DFSClient.getFileInfo(DFSClient.java:2116) at org.apache.hadoop.hdfs.DistributedFileSystem$22.doCall(DistributedFileSystem.java:1315) at org.apache.hadoop.hdfs.DistributedFileSystem$22.doCall(DistributedFileSystem.java:1311) at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81) at org.apache.hadoop.hdfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:1311) at org.apache.hadoop.fs.FilterFileSystem.getFileStatus(FilterFileSystem.java:421) at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:1424) at org.apache.hadoop.fs.FileSystem.createNewFile(FileSystem.java:1149) at org.apache.hadoop.hbase.wal.WALSplitter.writeRegionSequenceIdFile(WALSplitter.java:716) at org.apache.hadoop.hbase.regionserver.HRegion.initializeRegionInternals(HRegion.java:860) at org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:794) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6328) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6289) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6260) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6216) at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:6167) at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:362) at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:129) at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.InterruptedException at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:400) at java.util.concurrent.FutureTask.get(FutureTask.java:187) at org.apache.hadoop.ipc.Client$Connection.sendRpcRequest(Client.java:1057) at org.apache.hadoop.ipc.Client.call(Client.java:1400) ... 37 more 2017-01-25 21:22:57,427 INFO [RS_OPEN_META-sandbox:16020-0] coordination.ZkOpenRegionCoordination: Opening of region {ENCODED => 1588230740, NAME => 'hbase:meta,,1', STARTKEY => '', ENDKEY => ''} failed, transitioning from OPENING to FAILED_OPEN in ZK, expecting version 13 2017-01-25 21:22:57,427 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] zookeeper.ZooKeeper: Session: 0x159c7c98b6700af closed 2017-01-25 21:22:57,427 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] regionserver.HRegionServer: stopping server sandbox.hortonworks.com,16020,1485379339918; zookeeper connection closed. 2017-01-25 21:22:57,427 INFO [regionserver/sandbox.hortonworks.com/10.0.2.15:16020] regionserver.HRegionServer: regionserver/sandbox.hortonworks.com/10.0.2.15:16020 exiting 2017-01-25 21:22:57,428 INFO [main-EventThread] zookeeper.ClientCnxn: EventThread shut down 2017-01-25 21:22:57,428 ERROR [main] regionserver.HRegionServerCommandLine: Region server exiting java.lang.RuntimeException: HRegionServer Aborted at org.apache.hadoop.hbase.regionserver.HRegionServerCommandLine.start(HRegionServerCommandLine.java:68) at org.apache.hadoop.hbase.regionserver.HRegionServerCommandLine.run(HRegionServerCommandLine.java:87) at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:76) at org.apache.hadoop.hbase.util.ServerCommandLine.doMain(ServerCommandLine.java:126) at org.apache.hadoop.hbase.regionserver.HRegionServer.main(HRegionServer.java:2651) 2017-01-25 21:22:57,430 WARN [RS_OPEN_META-sandbox:16020-0] zookeeper.RecoverableZooKeeper: Possibly transient ZooKeeper, quorum=sandbox.hortonworks.com:2181, exception=org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /hbase-unsecure/region-in-transition/1588230740 2017-01-25 21:22:57,438 WARN [RS_OPEN_META-sandbox:16020-0] zookeeper.ZKUtil: regionserver:16020-0x159c7c98b6700af, quorum=sandbox.hortonworks.com:2181, baseZNode=/hbase-unsecure Unable to get data of znode /hbase-unsecure/region-in-transition/1588230740 java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at java.lang.Thread.sleep(Thread.java:340) at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:360) at org.apache.hadoop.hbase.util.RetryCounter.sleepUntilNextRetry(RetryCounter.java:158) at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.getData(RecoverableZooKeeper.java:373) at org.apache.hadoop.hbase.zookeeper.ZKUtil.getDataNoWatch(ZKUtil.java:711) at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNode(ZKAssign.java:814) at org.apache.hadoop.hbase.zookeeper.ZKAssign.transitionNode(ZKAssign.java:795) at org.apache.hadoop.hbase.coordination.ZkOpenRegionCoordination.tryTransitionFromOpeningToFailedOpen(ZkOpenRegionCoordination.java:233) at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.doCleanUpOnFailedOpen(OpenRegionHandler.java:218) at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:177) at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2017-01-25 21:22:57,438 WARN [RS_OPEN_META-sandbox:16020-0] coordination.ZkOpenRegionCoordination: Unable to mark region {ENCODED => 1588230740, NAME => 'hbase:meta,,1', STARTKEY => '', ENDKEY => ''} as FAILED_OPEN. It's likely that the master already timed out this open attempt, and thus another RS already has the region. 2017-01-25 21:22:57,437 INFO [Thread-80] provider.AuditProviderFactory: ==> JVMShutdownHook.run() 2017-01-25 21:22:57,476 INFO [Thread-80] queue.AuditAsyncQueue: Stop called. name=hbaseRegional.async 2017-01-25 21:22:57,476 INFO [Thread-80] queue.AuditAsyncQueue: Interrupting consumerThread. name=hbaseRegional.async, consumer=hbaseRegional.async.summary 2017-01-25 21:22:57,476 INFO [Thread-80] provider.AuditProviderFactory: <== JVMShutdownHook.run() 2017-01-25 21:22:57,476 INFO [org.apache.ranger.audit.queue.AuditAsyncQueue0] queue.AuditAsyncQueue: Caught exception in consumer thread. Shutdown might be in progress 2017-01-25 21:22:57,477 INFO [org.apache.ranger.audit.queue.AuditAsyncQueue0] queue.AuditAsyncQueue: Exiting polling loop. name=hbaseRegional.async 2017-01-25 21:22:57,477 INFO [org.apache.ranger.audit.queue.AuditAsyncQueue0] queue.AuditAsyncQueue: Calling to stop consumer. name=hbaseRegional.async, consumer.name=hbaseRegional.async.summary 2017-01-25 21:22:57,477 INFO [org.apache.ranger.audit.queue.AuditAsyncQueue0] queue.AuditSummaryQueue: Stop called. name=hbaseRegional.async.summary 2017-01-25 21:22:57,477 INFO [org.apache.ranger.audit.queue.AuditAsyncQueue0] queue.AuditSummaryQueue: Interrupting consumerThread. name=hbaseRegional.async.summary, consumer=hbaseRegional.async.summary.multi_dest 2017-01-25 21:22:57,477 INFO [org.apache.ranger.audit.queue.AuditAsyncQueue0] queue.AuditAsyncQueue: Exiting consumerThread.run() method. name=hbaseRegional.async 2017-01-25 21:22:57,477 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditSummaryQueue: Caught exception in consumer thread. Shutdown might be in progress 2017-01-25 21:22:57,481 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditSummaryQueue: Exiting polling loop. name=hbaseRegional.async.summary 2017-01-25 21:22:57,482 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditSummaryQueue: Calling to stop consumer. name=hbaseRegional.async.summary, consumer.name=hbaseRegional.async.summary.multi_dest 2017-01-25 21:22:57,482 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditBatchQueue: Stop called. name=hbaseRegional.async.summary.multi_dest.batch 2017-01-25 21:22:57,482 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditBatchQueue: Interrupting consumerThread. name=hbaseRegional.async.summary.multi_dest.batch, consumer=hbaseRegional.async.summary.multi_dest.batch.db 2017-01-25 21:22:57,482 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditBatchQueue: Stop called. name=hbaseRegional.async.summary.multi_dest.batch 2017-01-25 21:22:57,482 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditBatchQueue: Interrupting consumerThread. name=hbaseRegional.async.summary.multi_dest.batch, consumer=hbaseRegional.async.summary.multi_dest.batch.hdfs 2017-01-25 21:22:57,483 INFO [org.apache.ranger.audit.queue.AuditSummaryQueue0] queue.AuditSummaryQueue: Exiting consumerThread.run() method. name=hbaseRegional.async.summary 2017-01-25 21:22:57,483 INFO [org.apache.ranger.audit.queue.AuditBatchQueue0] queue.AuditBatchQueue: Caught exception in consumer thread. Shutdown might be in progress 2017-01-25 21:22:57,485 INFO [org.apache.ranger.audit.queue.AuditBatchQueue0] queue.AuditBatchQueue: Exiting consumerThread. Queue=hbaseRegional.async.summary.multi_dest.batch, dest=hbaseRegional.async.summary.multi_dest.batch.db 2017-01-25 21:22:57,486 INFO [org.apache.ranger.audit.queue.AuditBatchQueue0] queue.AuditBatchQueue: Calling to stop consumer. name=hbaseRegional.async.summary.multi_dest.batch, consumer.name=hbaseRegional.async.summary.multi_dest.batch.db 2017-01-25 21:22:57,488 INFO [org.apache.ranger.audit.queue.AuditBatchQueue0] destination.DBAuditDestination: DBAuditDestination: cleanUp() 2017-01-25 21:22:57,485 INFO [Thread-7] regionserver.ShutdownHook: Shutdown hook starting; hbase.shutdown.hook=true; fsShutdownHook=org.apache.hadoop.fs.FileSystem$Cache$ClientFinalizer@7817b700 2017-01-25 21:22:57,484 INFO [org.apache.ranger.audit.queue.AuditBatchQueue1] queue.AuditBatchQueue: Caught exception in consumer thread. Shutdown might be in progress 2017-01-25 21:22:57,490 INFO [org.apache.ranger.audit.queue.AuditBatchQueue1] queue.AuditBatchQueue: Exiting consumerThread. Queue=hbaseRegional.async.summary.multi_dest.batch, dest=hbaseRegional.async.summary.multi_dest.batch.hdfs 2017-01-25 21:22:57,490 INFO [org.apache.ranger.audit.queue.AuditBatchQueue1] queue.AuditBatchQueue: Calling to stop consumer. name=hbaseRegional.async.summary.multi_dest.batch, consumer.name=hbaseRegional.async.summary.multi_dest.batch.hdfs 2017-01-25 21:22:57,490 INFO [org.apache.ranger.audit.queue.AuditBatchQueue1] queue.AuditFileSpool: Stop called, queueName=hbaseRegional.async.summary.multi_dest.batch, consumer=hbaseRegional.async.summary.multi_dest.batch.hdfs 2017-01-25 21:22:57,491 INFO [org.apache.ranger.audit.queue.AuditBatchQueue1] queue.AuditBatchQueue: Exiting consumerThread.run() method. name=hbaseRegional.async.summary.multi_dest.batch 2017-01-25 21:22:57,491 INFO [hbaseRegional.async.summary.multi_dest.batch_hbaseRegional.async.summary.multi_dest.batch.hdfs_destWriter] queue.AuditFileSpool: Caught exception in consumer thread. Shutdown might be in progress 2017-01-25 21:22:57,492 INFO [Thread-7] regionserver.ShutdownHook: Starting fs shutdown hook thread. 2017-01-25 21:22:57,502 INFO [org.apache.ranger.audit.queue.AuditBatchQueue0] queue.AuditFileSpool: Stop called, queueName=hbaseRegional.async.summary.multi_dest.batch, consumer=hbaseRegional.async.summary.multi_dest.batch.db 2017-01-25 21:22:57,503 INFO [org.apache.ranger.audit.queue.AuditBatchQueue0] queue.AuditBatchQueue: Exiting consumerThread.run() method. name=hbaseRegional.async.summary.multi_dest.batch 2017-01-25 21:22:57,503 INFO [hbaseRegional.async.summary.multi_dest.batch_hbaseRegional.async.summary.multi_dest.batch.db_destWriter] queue.AuditFileSpool: Caught exception in consumer thread. Shutdown might be in progress 2017-01-25 21:22:57,503 INFO [Thread-7] regionserver.ShutdownHook: Shutdown hook finished.