[
https://issues.apache.org/jira/browse/OOZIE-3138?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Denes Bodo updated OOZIE-3138:
------------------------------
Affects Version/s: 4.2.0
> TestSparkMain.testMain UT fails
> -------------------------------
>
> Key: OOZIE-3138
> URL: https://issues.apache.org/jira/browse/OOZIE-3138
> Project: Oozie
> Issue Type: Test
> Components: tests
> Affects Versions: 4.2.0
> Reporter: Yesha Vora
>
> TestSparkMain.testMain UT fails with below error
> {code}
> Error Message
> java.lang.RuntimeException: Unable to instantiate
> org.apache.hive.hcatalog.common.HiveClientCache$CacheableHiveMetaStoreClient
> Stacktrace
> com.google.common.util.concurrent.UncheckedExecutionException:
> java.lang.RuntimeException: Unable to instantiate
> org.apache.hive.hcatalog.common.HiveClientCache$CacheableHiveMetaStoreClient
> at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2263)
> at com.google.common.cache.LocalCache.get(LocalCache.java:4000)
> at
> com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4789)
> at
> org.apache.hive.hcatalog.common.HiveClientCache.getOrCreate(HiveClientCache.java:291)
> at
> org.apache.hive.hcatalog.common.HiveClientCache.get(HiveClientCache.java:273)
> at
> org.apache.hive.hcatalog.common.HCatUtil.getHiveMetastoreClient(HCatUtil.java:558)
> at
> org.apache.hive.hcatalog.api.HCatClientHMSImpl.initialize(HCatClientHMSImpl.java:823)
> at org.apache.hive.hcatalog.api.HCatClient.create(HCatClient.java:71)
> at org.apache.oozie.test.MiniHCatServer.start(MiniHCatServer.java:87)
> at
> org.apache.oozie.test.XTestCase.setupHCatalogServer(XTestCase.java:998)
> at org.apache.oozie.test.XTestCase.setUp(XTestCase.java:405)
> at org.apache.oozie.test.XTestCase.setUp(XTestCase.java:281)
> at org.apache.oozie.test.XFsTestCase.setUp(XFsTestCase.java:61)
> at junit.framework.TestCase.runBare(TestCase.java:132)
> at junit.framework.TestResult$1.protect(TestResult.java:110)
> at junit.framework.TestResult.runProtected(TestResult.java:128)
> at junit.framework.TestResult.run(TestResult.java:113)
> at junit.framework.TestCase.run(TestCase.java:124)
> at junit.framework.TestSuite.runTest(TestSuite.java:243)
> at junit.framework.TestSuite.run(TestSuite.java:238)
> at
> org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)
> at org.junit.runners.Suite.runChild(Suite.java:128)
> at org.junit.runners.Suite.runChild(Suite.java:24)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.RuntimeException: Unable to instantiate
> org.apache.hive.hcatalog.common.HiveClientCache$CacheableHiveMetaStoreClient
> at
> org.apache.hadoop.hive.metastore.MetaStoreUtils.newInstance(MetaStoreUtils.java:1566)
> at
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.<init>(RetryingMetaStoreClient.java:92)
> at
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:138)
> at
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:124)
> at
> org.apache.hive.hcatalog.common.HiveClientCache$5.call(HiveClientCache.java:295)
> at
> org.apache.hive.hcatalog.common.HiveClientCache$5.call(HiveClientCache.java:291)
> at
> com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4792)
> at
> com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3599)
> at
> com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2379)
> at
> com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2342)
> at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2257)
> ... 28 more
> Caused by: java.lang.reflect.InvocationTargetException
> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
> at
> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
> at
> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
> at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
> at
> org.apache.hadoop.hive.metastore.MetaStoreUtils.newInstance(MetaStoreUtils.java:1564)
> ... 38 more
> Caused by: MetaException(message:Could not connect to meta store using any of
> the URIs provided. Most recent failure:
> org.apache.thrift.transport.TTransportException: java.net.ConnectException:
> Connection refused
> at org.apache.thrift.transport.TSocket.open(TSocket.java:187)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.open(HiveMetaStoreClient.java:487)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.<init>(HiveMetaStoreClient.java:282)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.<init>(HiveMetaStoreClient.java:188)
> at
> org.apache.hive.hcatalog.common.HiveClientCache$CacheableHiveMetaStoreClient.<init>(HiveClientCache.java:406)
> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
> at
> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
> at
> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
> at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
> at
> org.apache.hadoop.hive.metastore.MetaStoreUtils.newInstance(MetaStoreUtils.java:1564)
> at
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.<init>(RetryingMetaStoreClient.java:92)
> at
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:138)
> at
> org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.getProxy(RetryingMetaStoreClient.java:124)
> at
> org.apache.hive.hcatalog.common.HiveClientCache$5.call(HiveClientCache.java:295)
> at
> org.apache.hive.hcatalog.common.HiveClientCache$5.call(HiveClientCache.java:291)
> at
> com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4792)
> at
> com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3599)
> at
> com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2379)
> at
> com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2342)
> at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2257)
> at com.google.common.cache.LocalCache.get(LocalCache.java:4000)
> at
> com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4789)
> at
> org.apache.hive.hcatalog.common.HiveClientCache.getOrCreate(HiveClientCache.java:291)
> at
> org.apache.hive.hcatalog.common.HiveClientCache.get(HiveClientCache.java:273)
> at
> org.apache.hive.hcatalog.common.HCatUtil.getHiveMetastoreClient(HCatUtil.java:558)
> at
> org.apache.hive.hcatalog.api.HCatClientHMSImpl.initialize(HCatClientHMSImpl.java:823)
> at org.apache.hive.hcatalog.api.HCatClient.create(HCatClient.java:71)
> at org.apache.oozie.test.MiniHCatServer.start(MiniHCatServer.java:87)
> at
> org.apache.oozie.test.XTestCase.setupHCatalogServer(XTestCase.java:998)
> at org.apache.oozie.test.XTestCase.setUp(XTestCase.java:405)
> at org.apache.oozie.test.XTestCase.setUp(XTestCase.java:281)
> at org.apache.oozie.test.XFsTestCase.setUp(XFsTestCase.java:61)
> at junit.framework.TestCase.runBare(TestCase.java:132)
> at junit.framework.TestResult$1.protect(TestResult.java:110)
> at junit.framework.TestResult.runProtected(TestResult.java:128)
> at junit.framework.TestResult.run(TestResult.java:113)
> at junit.framework.TestCase.run(TestCase.java:124)
> at junit.framework.TestSuite.runTest(TestSuite.java:243)
> at junit.framework.TestSuite.run(TestSuite.java:238)
> at
> org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)
> at org.junit.runners.Suite.runChild(Suite.java:128)
> at org.junit.runners.Suite.runChild(Suite.java:24)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at
> java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
> at
> java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
> at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:589)
> at org.apache.thrift.transport.TSocket.open(TSocket.java:182)
> ... 47 more
> )
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.open(HiveMetaStoreClient.java:534)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.<init>(HiveMetaStoreClient.java:282)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStoreClient.<init>(HiveMetaStoreClient.java:188)
> at
> org.apache.hive.hcatalog.common.HiveClientCache$CacheableHiveMetaStoreClient.<init>(HiveClientCache.java:406)
> ... 43 more
> Standard Output
> Setting testcase work
> dir[/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/test-data/oozietests/org.apache.oozie.action.hadoop.TestSparkMain/testMain]
> 2017-11-28 15:41:48,529 WARN [pool-1-thread-1] conf.Configuration
> (Configuration.java:<clinit>(664)) - DEPRECATED: hadoop-site.xml found in the
> classpath. Usage of hadoop-site.xml is deprecated. Instead use core-site.xml,
> mapred-site.xml and hdfs-site.xml to override properties of core-default.xml,
> mapred-default.xml and hdfs-default.xml respectively
> 2017-11-28 15:41:48,961 INFO [pool-1-thread-1] Configuration.deprecation
> (Configuration.java:warnOnceIfDeprecated(1194)) -
> mapred.tasktracker.map.tasks.maximum is deprecated. Instead, use
> mapreduce.tasktracker.map.tasks.maximum
> 2017-11-28 15:41:48,962 INFO [pool-1-thread-1] Configuration.deprecation
> (Configuration.java:warnOnceIfDeprecated(1194)) -
> mapred.tasktracker.reduce.tasks.maximum is deprecated. Instead, use
> mapreduce.tasktracker.reduce.tasks.maximum
> 2017-11-28 15:41:49,139 WARN [pool-1-thread-1] util.NativeCodeLoader
> (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library
> for your platform... using builtin-java classes where applicable
> Formatting using clusterid: testClusterID
> 2017-11-28 15:41:49,576 INFO [pool-1-thread-1] namenode.FSEditLog
> (FSEditLog.java:newInstance(225)) - Edit logging is async:false
> 2017-11-28 15:41:49,582 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(758)) - No KeyProvider found.
> 2017-11-28 15:41:49,583 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(768)) - fsLock is fair:true
> 2017-11-28 15:41:49,644 INFO [pool-1-thread-1] common.Util
> (Util.java:isDiskStatsEnabled(111)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-11-28 15:41:49,653 INFO [pool-1-thread-1] Configuration.deprecation
> (Configuration.java:warnOnceIfDeprecated(1194)) -
> hadoop.configured.node.mapping is deprecated. Instead, use
> net.topology.configured.node.mapping
> 2017-11-28 15:41:49,653 INFO [pool-1-thread-1]
> blockmanagement.DatanodeManager (DatanodeManager.java:<init>(274)) -
> dfs.block.invalidate.limit=1000
> 2017-11-28 15:41:49,653 INFO [pool-1-thread-1]
> blockmanagement.DatanodeManager (DatanodeManager.java:<init>(280)) -
> dfs.namenode.datanode.registration.ip-hostname-check=true
> 2017-11-28 15:41:49,658 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(71)) -
> dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
> 2017-11-28 15:41:49,660 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(76)) - The block deletion will
> start around 2017 Nov 28 15:41:49
> 2017-11-28 15:41:49,664 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> BlocksMap
> 2017-11-28 15:41:49,664 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:49,667 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 2.0% max memory 981.5 MB = 19.6
> MB
> 2017-11-28 15:41:49,668 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^21 = 2097152
> entries
> 2017-11-28 15:41:49,697 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:createBlockTokenSecretManager(409)) -
> dfs.block.access.token.enable=false
> 2017-11-28 15:41:49,701 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(395)) - defaultReplication = 2
> 2017-11-28 15:41:49,701 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(396)) - maxReplication = 512
> 2017-11-28 15:41:49,701 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(397)) - minReplication = 1
> 2017-11-28 15:41:49,701 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(398)) - maxReplicationStreams = 2
> 2017-11-28 15:41:49,701 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(399)) - replicationRecheckInterval = 3000
> 2017-11-28 15:41:49,701 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(400)) - encryptDataTransfer = false
> 2017-11-28 15:41:49,702 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(401)) - maxNumBlocksToLog = 1000
> 2017-11-28 15:41:49,754 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(789)) - fsOwner = nobody (auth:SIMPLE)
> 2017-11-28 15:41:49,754 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(790)) - supergroup = supergroup
> 2017-11-28 15:41:49,754 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(791)) - isPermissionEnabled = true
> 2017-11-28 15:41:49,755 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(802)) - HA Enabled: false
> 2017-11-28 15:41:49,759 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(839)) - Append Enabled: true
> 2017-11-28 15:41:49,995 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> INodeMap
> 2017-11-28 15:41:49,995 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:49,996 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 1.0% max memory 981.5 MB = 9.8
> MB
> 2017-11-28 15:41:49,996 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^20 = 1048576
> entries
> 2017-11-28 15:41:49,999 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:<init>(256)) - ACLs enabled? false
> 2017-11-28 15:41:50,000 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:<init>(260)) - XAttrs enabled? true
> 2017-11-28 15:41:50,000 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:<init>(268)) - Maximum size of an xattr: 16384
> 2017-11-28 15:41:50,000 INFO [pool-1-thread-1] namenode.NameNode
> (FSDirectory.java:<init>(321)) - Caching file names occuring more than 10
> times
> 2017-11-28 15:41:50,013 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> cachedBlocks
> 2017-11-28 15:41:50,013 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:50,014 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.25% max memory 981.5 MB = 2.5
> MB
> 2017-11-28 15:41:50,014 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^18 = 262144
> entries
> 2017-11-28 15:41:50,016 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(5574)) - dfs.namenode.safemode.threshold-pct =
> 0.9990000128746033
> 2017-11-28 15:41:50,017 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(5575)) - dfs.namenode.safemode.min.datanodes = 0
> 2017-11-28 15:41:50,017 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(5576)) - dfs.namenode.safemode.extension = 0
> 2017-11-28 15:41:50,023 INFO [pool-1-thread-1] metrics.TopMetrics
> (TopMetrics.java:logConf(76)) - NNTop conf:
> dfs.namenode.top.window.num.buckets = 10
> 2017-11-28 15:41:50,023 INFO [pool-1-thread-1] metrics.TopMetrics
> (TopMetrics.java:logConf(78)) - NNTop conf: dfs.namenode.top.num.users = 10
> 2017-11-28 15:41:50,023 INFO [pool-1-thread-1] metrics.TopMetrics
> (TopMetrics.java:logConf(80)) - NNTop conf: dfs.namenode.top.windows.minutes
> = 1,5,25
> 2017-11-28 15:41:50,091 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(967)) - Retry cache on namenode is enabled
> 2017-11-28 15:41:50,092 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(975)) - Retry cache will use 0.03 of total
> heap and retry cache entry expiry time is 600000 millis
> 2017-11-28 15:41:50,096 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> NameNodeRetryCache
> 2017-11-28 15:41:50,096 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:50,096 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.029999999329447746% max
> memory 981.5 MB = 301.5 KB
> 2017-11-28 15:41:50,096 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^15 = 32768
> entries
> 2017-11-28 15:41:50,180 INFO [pool-1-thread-1] namenode.FSImage
> (FSImage.java:format(153)) - Allocated new BlockPoolId:
> BP-1089370620-172.27.58.198-1511883710117
> 2017-11-28 15:41:50,195 INFO [pool-1-thread-1] common.Storage
> (NNStorage.java:format(566)) - Storage directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1
> has been successfully formatted.
> 2017-11-28 15:41:50,197 INFO [pool-1-thread-1] common.Storage
> (NNStorage.java:format(566)) - Storage directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name2
> has been successfully formatted.
> 2017-11-28 15:41:50,214 INFO [FSImageSaver for
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name2
> of type IMAGE_AND_EDITS] namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(413)) - Saving image file
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name2/current/fsimage.ckpt_0000000000000000000
> using no compression
> 2017-11-28 15:41:50,214 INFO [FSImageSaver for
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1
> of type IMAGE_AND_EDITS] namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(413)) - Saving image file
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1/current/fsimage.ckpt_0000000000000000000
> using no compression
> 2017-11-28 15:41:50,335 INFO [FSImageSaver for
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1
> of type IMAGE_AND_EDITS] namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(416)) - Image file
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1/current/fsimage.ckpt_0000000000000000000
> of size 323 bytes saved in 0 seconds.
> 2017-11-28 15:41:50,338 INFO [FSImageSaver for
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name2
> of type IMAGE_AND_EDITS] namenode.FSImageFormatProtobuf
> (FSImageFormatProtobuf.java:save(416)) - Image file
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name2/current/fsimage.ckpt_0000000000000000000
> of size 323 bytes saved in 0 seconds.
> 2017-11-28 15:41:50,353 INFO [pool-1-thread-1]
> namenode.NNStorageRetentionManager
> (NNStorageRetentionManager.java:getImageTxIdToRetain(203)) - Going to retain
> 1 images with txid >= 0
> 2017-11-28 15:41:50,357 INFO [pool-1-thread-1] namenode.NameNode
> (NameNode.java:createNameNode(1624)) - createNameNode []
> 2017-11-28 15:41:50,407 WARN [pool-1-thread-1] impl.MetricsConfig
> (MetricsConfig.java:loadFirst(125)) - Cannot locate configuration: tried
> hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
> 2017-11-28 15:41:50,495 INFO [pool-1-thread-1] impl.MetricsSystemImpl
> (MetricsSystemImpl.java:startTimer(376)) - Scheduled snapshot period at 10
> second(s).
> 2017-11-28 15:41:50,496 INFO [pool-1-thread-1] impl.MetricsSystemImpl
> (MetricsSystemImpl.java:start(192)) - NameNode metrics system started
> 2017-11-28 15:41:50,500 INFO [pool-1-thread-1] namenode.NameNode
> (NameNode.java:setClientNamenodeAddress(450)) - fs.defaultFS is
> hdfs://127.0.0.1:0
> 2017-11-28 15:41:50,535 INFO
> [org.apache.hadoop.util.JvmPauseMonitor$Monitor@77b45849]
> util.JvmPauseMonitor (JvmPauseMonitor.java:run(179)) - Starting JVM pause
> monitor
> 2017-11-28 15:41:50,561 INFO [pool-1-thread-1] hdfs.DFSUtil
> (DFSUtil.java:httpServerTemplateForNNAndJN(1803)) - Starting Web-server for
> hdfs at: http://localhost:0
> 2017-11-28 15:41:50,727 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - Logging to
> org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
> org.mortbay.log.Slf4jLog
> 2017-11-28 15:41:50,742 INFO [pool-1-thread-1] server.AuthenticationFilter
> (AuthenticationFilter.java:constructSecretProvider(296)) - Unable to
> initialize FileSignerSecretProvider, falling back to use random secrets.
> 2017-11-28 15:41:50,752 WARN [pool-1-thread-1] http.HttpRequestLog
> (HttpRequestLog.java:getRequestLog(100)) - Jetty request log can only be
> enabled using Log4j
> 2017-11-28 15:41:50,763 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addGlobalFilter(791)) - Added global filter 'safety'
> (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
> 2017-11-28 15:41:50,767 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(766)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context hdfs
> 2017-11-28 15:41:50,767 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(774)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context static
> 2017-11-28 15:41:50,771 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(774)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context logs
> 2017-11-28 15:41:50,771 INFO [pool-1-thread-1]
> security.HttpCrossOriginFilterInitializer
> (HttpCrossOriginFilterInitializer.java:initFilter(49)) - CORS filter not
> enabled. Please set hadoop.http.cross-origin.enabled to 'true' to enable it
> 2017-11-28 15:41:50,965 INFO [pool-1-thread-1] http.HttpServer2
> (NameNodeHttpServer.java:initWebHdfs(93)) - Added filter
> 'org.apache.hadoop.hdfs.web.AuthFilter'
> (class=org.apache.hadoop.hdfs.web.AuthFilter)
> 2017-11-28 15:41:50,969 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addJerseyResourcePackage(690)) - addJerseyResourcePackage:
> packageName=org.apache.hadoop.hdfs.server.namenode.web.resources;org.apache.hadoop.hdfs.web.resources,
> pathSpec=/webhdfs/v1/*
> 2017-11-28 15:41:50,997 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:bindListener(989)) - Jetty bound to port 46377
> 2017-11-28 15:41:50,998 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - jetty-6.1.14
> 2017-11-28 15:41:51,039 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - Extract
> jar:file:/grid/0/nobody/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.7.3.2.6.4.0-SNAPSHOT/hadoop-hdfs-2.7.3.2.6.4.0-SNAPSHOT-tests.jar!/webapps/hdfs
> to /tmp/Jetty_localhost_46377_hdfs____kc669n/webapp
> 2017-11-28 15:41:51,282 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - Started
> HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:46377
> 2017-11-28 15:41:51,288 INFO [pool-1-thread-1] namenode.FSEditLog
> (FSEditLog.java:newInstance(225)) - Edit logging is async:false
> 2017-11-28 15:41:51,289 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(758)) - No KeyProvider found.
> 2017-11-28 15:41:51,289 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(768)) - fsLock is fair:true
> 2017-11-28 15:41:51,289 INFO [pool-1-thread-1] common.Util
> (Util.java:isDiskStatsEnabled(111)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-11-28 15:41:51,290 INFO [pool-1-thread-1]
> blockmanagement.DatanodeManager (DatanodeManager.java:<init>(274)) -
> dfs.block.invalidate.limit=1000
> 2017-11-28 15:41:51,290 INFO [pool-1-thread-1]
> blockmanagement.DatanodeManager (DatanodeManager.java:<init>(280)) -
> dfs.namenode.datanode.registration.ip-hostname-check=true
> 2017-11-28 15:41:51,290 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(71)) -
> dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
> 2017-11-28 15:41:51,291 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (InvalidateBlocks.java:printBlockDeletionTime(76)) - The block deletion will
> start around 2017 Nov 28 15:41:51
> 2017-11-28 15:41:51,291 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> BlocksMap
> 2017-11-28 15:41:51,291 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:51,291 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 2.0% max memory 910.5 MB = 18.2
> MB
> 2017-11-28 15:41:51,292 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^21 = 2097152
> entries
> 2017-11-28 15:41:51,295 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:createBlockTokenSecretManager(409)) -
> dfs.block.access.token.enable=false
> 2017-11-28 15:41:51,295 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(395)) - defaultReplication = 2
> 2017-11-28 15:41:51,295 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(396)) - maxReplication = 512
> 2017-11-28 15:41:51,295 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(397)) - minReplication = 1
> 2017-11-28 15:41:51,296 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(398)) - maxReplicationStreams = 2
> 2017-11-28 15:41:51,296 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(399)) - replicationRecheckInterval = 3000
> 2017-11-28 15:41:51,296 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(400)) - encryptDataTransfer = false
> 2017-11-28 15:41:51,296 INFO [pool-1-thread-1] blockmanagement.BlockManager
> (BlockManager.java:<init>(401)) - maxNumBlocksToLog = 1000
> 2017-11-28 15:41:51,296 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(789)) - fsOwner = nobody (auth:SIMPLE)
> 2017-11-28 15:41:51,296 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(790)) - supergroup = supergroup
> 2017-11-28 15:41:51,296 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(791)) - isPermissionEnabled = true
> 2017-11-28 15:41:51,297 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(802)) - HA Enabled: false
> 2017-11-28 15:41:51,297 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(839)) - Append Enabled: true
> 2017-11-28 15:41:51,297 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> INodeMap
> 2017-11-28 15:41:51,297 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:51,298 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 1.0% max memory 910.5 MB = 9.1
> MB
> 2017-11-28 15:41:51,298 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^20 = 1048576
> entries
> 2017-11-28 15:41:51,299 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:<init>(256)) - ACLs enabled? false
> 2017-11-28 15:41:51,300 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:<init>(260)) - XAttrs enabled? true
> 2017-11-28 15:41:51,300 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:<init>(268)) - Maximum size of an xattr: 16384
> 2017-11-28 15:41:51,300 INFO [pool-1-thread-1] namenode.NameNode
> (FSDirectory.java:<init>(321)) - Caching file names occuring more than 10
> times
> 2017-11-28 15:41:51,300 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> cachedBlocks
> 2017-11-28 15:41:51,300 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:51,300 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.25% max memory 910.5 MB = 2.3
> MB
> 2017-11-28 15:41:51,301 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^18 = 262144
> entries
> 2017-11-28 15:41:51,301 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(5574)) - dfs.namenode.safemode.threshold-pct =
> 0.9990000128746033
> 2017-11-28 15:41:51,302 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(5575)) - dfs.namenode.safemode.min.datanodes = 0
> 2017-11-28 15:41:51,302 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:<init>(5576)) - dfs.namenode.safemode.extension = 0
> 2017-11-28 15:41:51,302 INFO [pool-1-thread-1] metrics.TopMetrics
> (TopMetrics.java:logConf(76)) - NNTop conf:
> dfs.namenode.top.window.num.buckets = 10
> 2017-11-28 15:41:51,302 INFO [pool-1-thread-1] metrics.TopMetrics
> (TopMetrics.java:logConf(78)) - NNTop conf: dfs.namenode.top.num.users = 10
> 2017-11-28 15:41:51,302 INFO [pool-1-thread-1] metrics.TopMetrics
> (TopMetrics.java:logConf(80)) - NNTop conf: dfs.namenode.top.windows.minutes
> = 1,5,25
> 2017-11-28 15:41:51,302 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(967)) - Retry cache on namenode is enabled
> 2017-11-28 15:41:51,303 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:initRetryCache(975)) - Retry cache will use 0.03 of total
> heap and retry cache entry expiry time is 600000 millis
> 2017-11-28 15:41:51,303 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(395)) - Computing capacity for map
> NameNodeRetryCache
> 2017-11-28 15:41:51,303 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(396)) - VM type = 64-bit
> 2017-11-28 15:41:51,303 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(397)) - 0.029999999329447746% max
> memory 910.5 MB = 279.7 KB
> 2017-11-28 15:41:51,303 INFO [pool-1-thread-1] util.GSet
> (LightWeightGSet.java:computeCapacity(402)) - capacity = 2^15 = 32768
> entries
> 2017-11-28 15:41:51,308 INFO [pool-1-thread-1] common.Storage
> (Storage.java:tryLock(776)) - Lock on
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1/in_use.lock
> acquired by nodename [email protected]
> 2017-11-28 15:41:51,311 INFO [pool-1-thread-1] common.Storage
> (Storage.java:tryLock(776)) - Lock on
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name2/in_use.lock
> acquired by nodename [email protected]
> 2017-11-28 15:41:51,314 INFO [pool-1-thread-1] namenode.FileJournalManager
> (FileJournalManager.java:recoverUnfinalizedSegments(388)) - Recovering
> unfinalized segments in
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1/current
> 2017-11-28 15:41:51,314 INFO [pool-1-thread-1] namenode.FileJournalManager
> (FileJournalManager.java:recoverUnfinalizedSegments(388)) - Recovering
> unfinalized segments in
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name2/current
> 2017-11-28 15:41:51,314 INFO [pool-1-thread-1] namenode.FSImage
> (FSImage.java:loadFSImage(664)) - No edit log streams selected.
> 2017-11-28 15:41:51,314 INFO [pool-1-thread-1] namenode.FSImage
> (FSImage.java:loadFSImageFile(731)) - Planning to load image:
> FSImageFile(file=/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1/current/fsimage_0000000000000000000,
> cpktTxId=0000000000000000000)
> 2017-11-28 15:41:51,331 INFO [pool-1-thread-1] namenode.FSImageFormatPBINode
> (FSImageFormatPBINode.java:loadINodeSection(257)) - Loading 1 INodes.
> 2017-11-28 15:41:51,340 INFO [pool-1-thread-1]
> namenode.FSImageFormatProtobuf (FSImageFormatProtobuf.java:load(184)) -
> Loaded FSImage in 0 seconds.
> 2017-11-28 15:41:51,340 INFO [pool-1-thread-1] namenode.FSImage
> (FSImage.java:loadFSImage(897)) - Loaded image for txid 0 from
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/name1/current/fsimage_0000000000000000000
> 2017-11-28 15:41:51,345 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:loadFSImage(1079)) - Need to save fs image? false
> (staleImage=false, haEnabled=false, isRollingUpgrade=false)
> 2017-11-28 15:41:51,345 INFO [pool-1-thread-1] namenode.FSEditLog
> (FSEditLog.java:startLogSegment(1294)) - Starting log segment at 1
> 2017-11-28 15:41:51,372 INFO [pool-1-thread-1] namenode.NameCache
> (NameCache.java:initialized(143)) - initialized with 0 entries 0 lookups
> 2017-11-28 15:41:51,372 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:loadFromDisk(730)) - Finished loading FSImage in 68 msecs
> 2017-11-28 15:41:51,638 INFO [pool-1-thread-1] namenode.NameNode
> (NameNodeRpcServer.java:<init>(428)) - RPC server is binding to localhost:0
> 2017-11-28 15:41:51,649 INFO [pool-1-thread-1] ipc.CallQueueManager
> (CallQueueManager.java:<init>(75)) - Using callQueue: class
> java.util.concurrent.LinkedBlockingQueue scheduler: class
> org.apache.hadoop.ipc.DefaultRpcScheduler
> 2017-11-28 15:41:51,671 INFO [Socket Reader #1 for port 38503] ipc.Server
> (Server.java:run(821)) - Starting Socket Reader #1 for port 38503
> 2017-11-28 15:41:51,772 INFO [pool-1-thread-1] namenode.NameNode
> (NameNode.java:initialize(772)) - Clients are to use localhost:38503 to
> access this namenode/service.
> 2017-11-28 15:41:51,774 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:registerMBean(6509)) - Registered FSNamesystemState MBean
> 2017-11-28 15:41:51,794 INFO [pool-1-thread-1] namenode.LeaseManager
> (LeaseManager.java:getNumUnderConstructionBlocks(139)) - Number of blocks
> under construction: 0
> 2017-11-28 15:41:51,795 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:initializeReplQueues(1271)) - initializing replication
> queues
> 2017-11-28 15:41:51,795 INFO [pool-1-thread-1] hdfs.StateChange
> (FSNamesystem.java:leave(5661)) - STATE* Leaving safe mode after 0 secs
> 2017-11-28 15:41:51,795 INFO [pool-1-thread-1] hdfs.StateChange
> (FSNamesystem.java:leave(5673)) - STATE* Network topology has 0 racks and 0
> datanodes
> 2017-11-28 15:41:51,795 INFO [pool-1-thread-1] hdfs.StateChange
> (FSNamesystem.java:leave(5676)) - STATE* UnderReplicatedBlocks has 0 blocks
> 2017-11-28 15:41:51,806 INFO [pool-1-thread-1]
> blockmanagement.DatanodeDescriptor
> (DatanodeDescriptor.java:updateHeartbeatState(401)) - Number of failed
> storage changes from 0 to 0
> 2017-11-28 15:41:51,809 INFO [Replication Queue Initializer]
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(2936)) - Total number of blocks
> = 0
> 2017-11-28 15:41:51,809 INFO [Replication Queue Initializer]
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(2937)) - Number of invalid
> blocks = 0
> 2017-11-28 15:41:51,809 INFO [Replication Queue Initializer]
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(2938)) - Number of
> under-replicated blocks = 0
> 2017-11-28 15:41:51,809 INFO [Replication Queue Initializer]
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(2939)) - Number of
> over-replicated blocks = 0
> 2017-11-28 15:41:51,809 INFO [Replication Queue Initializer]
> blockmanagement.BlockManager
> (BlockManager.java:processMisReplicatesAsync(2941)) - Number of blocks being
> written = 0
> 2017-11-28 15:41:51,809 INFO [Replication Queue Initializer]
> hdfs.StateChange (BlockManager.java:processMisReplicatesAsync(2943)) - STATE*
> Replication Queue initialization scan for invalid, over- and under-replicated
> blocks completed in 15 msec
> 2017-11-28 15:41:51,810 INFO
> [org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor@23383605]
> BlockStateChange (BlockManager.java:computeReplicationWorkForBlocks(1653)) -
> BLOCK* neededReplications = 0, pendingReplications = 0.
> 2017-11-28 15:41:51,846 INFO [IPC Server listener on 38503] ipc.Server
> (Server.java:run(900)) - IPC Server listener on 38503: starting
> 2017-11-28 15:41:51,846 INFO [IPC Server Responder] ipc.Server
> (Server.java:run(1064)) - IPC Server Responder: starting
> 2017-11-28 15:41:51,850 INFO [pool-1-thread-1] namenode.NameNode
> (NameNode.java:startCommonServices(885)) - NameNode RPC up at:
> localhost/127.0.0.1:38503
> 2017-11-28 15:41:51,850 WARN [pool-1-thread-1] namenode.NameNode
> (NameNode.java:makeMetricsLoggerAsync(828)) - Metrics logging will not be
> async since the logger is not log4j
> 2017-11-28 15:41:51,851 INFO [pool-1-thread-1] namenode.FSNamesystem
> (FSNamesystem.java:startActiveServices(1187)) - Starting services required
> for active state
> 2017-11-28 15:41:51,851 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:updateCountForQuota(708)) - Initializing quota with 4
> thread(s)
> 2017-11-28 15:41:51,855 INFO [pool-1-thread-1] namenode.FSDirectory
> (FSDirectory.java:updateCountForQuota(717)) - Quota initialization completed
> in 3 milliseconds
> name space=1
> storage space=0
> storage types=RAM_DISK=0, SSD=0, DISK=0, ARCHIVE=0
> 2017-11-28 15:41:51,859 INFO [CacheReplicationMonitor(503514335)]
> blockmanagement.CacheReplicationMonitor
> (CacheReplicationMonitor.java:run(161)) - Starting CacheReplicationMonitor
> with interval 30000 milliseconds
> 2017-11-28 15:41:51,865 INFO [pool-1-thread-1] hdfs.MiniDFSCluster
> (MiniDFSCluster.java:startDataNodes(1458)) - Starting DataNode 0 with
> dfs.datanode.data.dir:
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1,[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2
> 2017-11-28 15:41:52,185 INFO [pool-1-thread-1] checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/
> 2017-11-28 15:41:52,208 INFO [pool-1-thread-1] checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/
> 2017-11-28 15:41:52,269 INFO [pool-1-thread-1] impl.MetricsSystemImpl
> (MetricsSystemImpl.java:init(159)) - DataNode metrics system started (again)
> 2017-11-28 15:41:52,273 INFO [pool-1-thread-1] datanode.BlockScanner
> (BlockScanner.java:<init>(180)) - Initialized block scanner with
> targetBytesPerSec 1048576
> 2017-11-28 15:41:52,277 INFO [pool-1-thread-1] common.Util
> (Util.java:isDiskStatsEnabled(111)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-11-28 15:41:52,281 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:<init>(455)) - Configured hostname is 127.0.0.1
> 2017-11-28 15:41:52,282 INFO [pool-1-thread-1] common.Util
> (Util.java:isDiskStatsEnabled(111)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-11-28 15:41:52,282 WARN [pool-1-thread-1] conf.Configuration
> (Configuration.java:getTimeDurationHelper(1592)) - No unit for
> dfs.datanode.outliers.report.interval(1800000) assuming MILLISECONDS
> 2017-11-28 15:41:52,287 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:startDataNode(1251)) - Starting DataNode with maxLockedMemory
> = 0
> 2017-11-28 15:41:52,299 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:initDataXceiver(1028)) - Opened streaming server at
> /127.0.0.1:37352
> 2017-11-28 15:41:52,303 INFO [pool-1-thread-1] datanode.DataNode
> (DataXceiverServer.java:<init>(78)) - Balancing bandwith is 1048576 bytes/s
> 2017-11-28 15:41:52,304 INFO [pool-1-thread-1] datanode.DataNode
> (DataXceiverServer.java:<init>(79)) - Number threads for balancing is 5
> 2017-11-28 15:41:52,316 INFO [pool-1-thread-1] server.AuthenticationFilter
> (AuthenticationFilter.java:constructSecretProvider(296)) - Unable to
> initialize FileSignerSecretProvider, falling back to use random secrets.
> 2017-11-28 15:41:52,317 WARN [pool-1-thread-1] http.HttpRequestLog
> (HttpRequestLog.java:getRequestLog(100)) - Jetty request log can only be
> enabled using Log4j
> 2017-11-28 15:41:52,318 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addGlobalFilter(791)) - Added global filter 'safety'
> (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
> 2017-11-28 15:41:52,319 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(766)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context datanode
> 2017-11-28 15:41:52,319 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(774)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context logs
> 2017-11-28 15:41:52,319 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(774)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context static
> 2017-11-28 15:41:52,319 INFO [pool-1-thread-1]
> security.HttpCrossOriginFilterInitializer
> (HttpCrossOriginFilterInitializer.java:initFilter(49)) - CORS filter not
> enabled. Please set hadoop.http.cross-origin.enabled to 'true' to enable it
> 2017-11-28 15:41:52,326 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:bindListener(989)) - Jetty bound to port 36342
> 2017-11-28 15:41:52,326 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - jetty-6.1.14
> 2017-11-28 15:41:52,331 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - Extract
> jar:file:/grid/0/nobody/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.7.3.2.6.4.0-SNAPSHOT/hadoop-hdfs-2.7.3.2.6.4.0-SNAPSHOT-tests.jar!/webapps/datanode
> to /tmp/Jetty_localhost_36342_datanode____.s94vhn/webapp
> 2017-11-28 15:41:52,465 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - Started
> HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:36342
> 2017-11-28 15:41:52,611 INFO [pool-1-thread-1] web.DatanodeHttpServer
> (DatanodeHttpServer.java:start(233)) - Listening HTTP traffic on
> /127.0.0.1:38743
> 2017-11-28 15:41:52,611 INFO
> [org.apache.hadoop.util.JvmPauseMonitor$Monitor@2f3cec05]
> util.JvmPauseMonitor (JvmPauseMonitor.java:run(179)) - Starting JVM pause
> monitor
> 2017-11-28 15:41:52,613 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:startDataNode(1277)) - dnUserName = nobody
> 2017-11-28 15:41:52,613 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:startDataNode(1278)) - supergroup = supergroup
> 2017-11-28 15:41:52,632 INFO [pool-1-thread-1] ipc.CallQueueManager
> (CallQueueManager.java:<init>(75)) - Using callQueue: class
> java.util.concurrent.LinkedBlockingQueue scheduler: class
> org.apache.hadoop.ipc.DefaultRpcScheduler
> 2017-11-28 15:41:52,633 INFO [Socket Reader #1 for port 41421] ipc.Server
> (Server.java:run(821)) - Starting Socket Reader #1 for port 41421
> 2017-11-28 15:41:52,647 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:initIpcServer(941)) - Opened IPC server at /127.0.0.1:41421
> 2017-11-28 15:41:52,660 INFO [pool-1-thread-1] datanode.DataNode
> (BlockPoolManager.java:refreshNamenodes(152)) - Refresh request received for
> nameservices: null
> 2017-11-28 15:41:52,663 INFO [pool-1-thread-1] datanode.DataNode
> (BlockPoolManager.java:doRefreshNamenodes(201)) - Starting BPOfferServices
> for nameservices: <default>
> 2017-11-28 15:41:52,676 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] datanode.DataNode
> (BPServiceActor.java:run(761)) - Block pool <registering> (Datanode Uuid
> unassigned) service to localhost/127.0.0.1:38503 starting to offer service
> 2017-11-28 15:41:52,683 INFO [IPC Server Responder] ipc.Server
> (Server.java:run(1064)) - IPC Server Responder: starting
> 2017-11-28 15:41:52,683 INFO [IPC Server listener on 41421] ipc.Server
> (Server.java:run(900)) - IPC Server listener on 41421: starting
> 2017-11-28 15:41:52,687 INFO [pool-1-thread-1] hdfs.MiniDFSCluster
> (MiniDFSCluster.java:startDataNodes(1458)) - Starting DataNode 1 with
> dfs.datanode.data.dir:
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3,[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4
> 2017-11-28 15:41:52,688 INFO [pool-1-thread-1] checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/
> 2017-11-28 15:41:52,689 INFO [pool-1-thread-1] checker.ThrottledAsyncChecker
> (ThrottledAsyncChecker.java:schedule(122)) - Scheduling a check for
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/
> 2017-11-28 15:41:52,705 INFO [pool-1-thread-1] impl.MetricsSystemImpl
> (MetricsSystemImpl.java:init(159)) - DataNode metrics system started (again)
> 2017-11-28 15:41:52,705 INFO [pool-1-thread-1] datanode.BlockScanner
> (BlockScanner.java:<init>(180)) - Initialized block scanner with
> targetBytesPerSec 1048576
> 2017-11-28 15:41:52,705 INFO [pool-1-thread-1] common.Util
> (Util.java:isDiskStatsEnabled(111)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-11-28 15:41:52,706 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:<init>(455)) - Configured hostname is 127.0.0.1
> 2017-11-28 15:41:52,706 INFO [pool-1-thread-1] common.Util
> (Util.java:isDiskStatsEnabled(111)) -
> dfs.datanode.fileio.profiling.sampling.percentage set to 0. Disabling file IO
> profiling
> 2017-11-28 15:41:52,706 WARN [pool-1-thread-1] conf.Configuration
> (Configuration.java:getTimeDurationHelper(1592)) - No unit for
> dfs.datanode.outliers.report.interval(1800000) assuming MILLISECONDS
> 2017-11-28 15:41:52,706 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:startDataNode(1251)) - Starting DataNode with maxLockedMemory
> = 0
> 2017-11-28 15:41:52,707 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:initDataXceiver(1028)) - Opened streaming server at
> /127.0.0.1:41272
> 2017-11-28 15:41:52,707 INFO [pool-1-thread-1] datanode.DataNode
> (DataXceiverServer.java:<init>(78)) - Balancing bandwith is 1048576 bytes/s
> 2017-11-28 15:41:52,707 INFO [pool-1-thread-1] datanode.DataNode
> (DataXceiverServer.java:<init>(79)) - Number threads for balancing is 5
> 2017-11-28 15:41:52,710 INFO [pool-1-thread-1] server.AuthenticationFilter
> (AuthenticationFilter.java:constructSecretProvider(296)) - Unable to
> initialize FileSignerSecretProvider, falling back to use random secrets.
> 2017-11-28 15:41:52,711 WARN [pool-1-thread-1] http.HttpRequestLog
> (HttpRequestLog.java:getRequestLog(100)) - Jetty request log can only be
> enabled using Log4j
> 2017-11-28 15:41:52,712 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addGlobalFilter(791)) - Added global filter 'safety'
> (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
> 2017-11-28 15:41:52,713 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(766)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context datanode
> 2017-11-28 15:41:52,713 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(774)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context static
> 2017-11-28 15:41:52,713 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:addFilter(774)) - Added filter static_user_filter
> (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to
> context logs
> 2017-11-28 15:41:52,713 INFO [pool-1-thread-1]
> security.HttpCrossOriginFilterInitializer
> (HttpCrossOriginFilterInitializer.java:initFilter(49)) - CORS filter not
> enabled. Please set hadoop.http.cross-origin.enabled to 'true' to enable it
> 2017-11-28 15:41:52,714 INFO [pool-1-thread-1] http.HttpServer2
> (HttpServer2.java:bindListener(989)) - Jetty bound to port 44682
> 2017-11-28 15:41:52,714 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - jetty-6.1.14
> 2017-11-28 15:41:52,719 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - Extract
> jar:file:/grid/0/nobody/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.7.3.2.6.4.0-SNAPSHOT/hadoop-hdfs-2.7.3.2.6.4.0-SNAPSHOT-tests.jar!/webapps/datanode
> to /tmp/Jetty_localhost_44682_datanode____.inx2i1/webapp
> 2017-11-28 15:41:52,856 INFO [pool-1-thread-1] mortbay.log
> (Slf4jLog.java:info(67)) - Started
> HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:44682
> 2017-11-28 15:41:52,871 INFO [pool-1-thread-1] web.DatanodeHttpServer
> (DatanodeHttpServer.java:start(233)) - Listening HTTP traffic on
> /127.0.0.1:45542
> 2017-11-28 15:41:52,872 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:startDataNode(1277)) - dnUserName = nobody
> 2017-11-28 15:41:52,872 INFO
> [org.apache.hadoop.util.JvmPauseMonitor$Monitor@376961fa]
> util.JvmPauseMonitor (JvmPauseMonitor.java:run(179)) - Starting JVM pause
> monitor
> 2017-11-28 15:41:52,872 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:startDataNode(1278)) - supergroup = supergroup
> 2017-11-28 15:41:52,872 INFO [pool-1-thread-1] ipc.CallQueueManager
> (CallQueueManager.java:<init>(75)) - Using callQueue: class
> java.util.concurrent.LinkedBlockingQueue scheduler: class
> org.apache.hadoop.ipc.DefaultRpcScheduler
> 2017-11-28 15:41:52,873 INFO [Socket Reader #1 for port 46351] ipc.Server
> (Server.java:run(821)) - Starting Socket Reader #1 for port 46351
> 2017-11-28 15:41:52,879 INFO [pool-1-thread-1] datanode.DataNode
> (DataNode.java:initIpcServer(941)) - Opened IPC server at /127.0.0.1:46351
> 2017-11-28 15:41:52,882 INFO [pool-1-thread-1] datanode.DataNode
> (BlockPoolManager.java:refreshNamenodes(152)) - Refresh request received for
> nameservices: null
> 2017-11-28 15:41:52,883 INFO [pool-1-thread-1] datanode.DataNode
> (BlockPoolManager.java:doRefreshNamenodes(201)) - Starting BPOfferServices
> for nameservices: <default>
> 2017-11-28 15:41:52,883 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/]]
> heartbeating to localhost/127.0.0.1:38503] datanode.DataNode
> (BPServiceActor.java:run(761)) - Block pool <registering> (Datanode Uuid
> unassigned) service to localhost/127.0.0.1:38503 starting to offer service
> 2017-11-28 15:41:52,884 INFO [IPC Server listener on 46351] ipc.Server
> (Server.java:run(900)) - IPC Server listener on 46351: starting
> 2017-11-28 15:41:52,885 INFO [IPC Server Responder] ipc.Server
> (Server.java:run(1064)) - IPC Server Responder: starting
> 2017-11-28 15:41:53,105 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:getParallelVolumeLoadThreadsNum(384)) - Using 2 threads to
> upgrade data directories (dfs.datanode.parallel.volumes.load.threads.num=2,
> dataDirs=2)
> 2017-11-28 15:41:53,105 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:getParallelVolumeLoadThreadsNum(384)) - Using 2 threads to
> upgrade data directories (dfs.datanode.parallel.volumes.load.threads.num=2,
> dataDirs=2)
> 2017-11-28 15:41:53,107 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (Storage.java:tryLock(776)) - Lock on
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/in_use.lock
> acquired by nodename [email protected]
> 2017-11-28 15:41:53,107 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (Storage.java:tryLock(776)) - Lock on
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/in_use.lock
> acquired by nodename [email protected]
> 2017-11-28 15:41:53,108 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:loadStorageDirectory(309)) - Storage directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1
> is not formatted for namespace 1907606034. Formatting...
> 2017-11-28 15:41:53,108 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:loadStorageDirectory(309)) - Storage directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3
> is not formatted for namespace 1907606034. Formatting...
> 2017-11-28 15:41:53,110 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:createStorageID(187)) - Generated new storageID
> DS-f0a27a63-d51e-48b5-aef1-2782ed1194d8 for directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1
> 2017-11-28 15:41:53,110 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:createStorageID(187)) - Generated new storageID
> DS-207ff42e-e232-4cb0-91e1-6c983d9187b2 for directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3
> 2017-11-28 15:41:53,114 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (Storage.java:tryLock(776)) - Lock on
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/in_use.lock
> acquired by nodename [email protected]
> 2017-11-28 15:41:53,114 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (Storage.java:tryLock(776)) - Lock on
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/in_use.lock
> acquired by nodename [email protected]
> 2017-11-28 15:41:53,115 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:loadStorageDirectory(309)) - Storage directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2
> is not formatted for namespace 1907606034. Formatting...
> 2017-11-28 15:41:53,116 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data3/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:loadStorageDirectory(309)) - Storage directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data4
> is not formatted for namespace 1907606034. Formatting...
> 2017-11-28 15:41:53,116 INFO [DataNode:
> [[[DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data1/,
>
> [DISK]file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/build/test/data/dfs/data/data2/]]
> heartbeating to localhost/127.0.0.1:38503] common.Storage
> (DataStorage.java:createStorageID(187)) - Generated new storageID
> DS-e9f121ff-b694-4e58-abaa-fdf4ac80b386 for directory
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/
> ...[truncated 5183895 chars]...
> pAttemptImpl:809 - appattempt_1511883728609_0005_000001 State change from
> LAUNCHED to RUNNING
> 16:04:00,539 INFO RMAppImpl:779 - application_1511883728609_0005 State
> change from ACCEPTED to RUNNING
> 16:04:00,578 INFO FSEditLog:771 - Number of transactions: 7405 Total time
> for transactions(ms): 205 Number of transactions batched in Syncs: 2919
> Number of syncs: 4486 SyncTimes(ms): 235 79
> 16:04:00,579 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1.jhist
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:00,659 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1_conf.xml
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:00,808 INFO StateChange:3862 - BLOCK* allocate blk_1073743269_2445,
> replicas=127.0.0.1:41272, 127.0.0.1:37352 for
> /tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1_conf.xml
> 16:04:00,894 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743269_2445 src:
> /127.0.0.1:44658 dest: /127.0.0.1:41272
> 16:04:00,895 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743269_2445 src:
> /127.0.0.1:51170 dest: /127.0.0.1:37352
> 16:04:00,938 INFO clienttrace:1490 - src: /127.0.0.1:51170, dest:
> /127.0.0.1:37352, bytes: 141926, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> c355628b-02f4-4102-9823-149c581be5bc, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743269_2445, duration:
> 41616333
> 16:04:00,938 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743269_2445,
> type=LAST_IN_PIPELINE terminating
> 16:04:00,939 INFO clienttrace:1490 - src: /127.0.0.1:44658, dest:
> /127.0.0.1:41272, bytes: 141926, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> 47252ceb-afae-4640-acde-3a2b425713b6, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743269_2445, duration:
> 42980160
> 16:04:00,939 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743269_2445,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:37352] terminating
> 16:04:00,944 INFO StateChange:3755 - DIR* completeFile:
> /tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1_conf.xml
> is closed by DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:01,039 INFO BlockManager:1660 - Blocks chosen but could not be
> replicated = 1; of which 1 have no target, 0 have no source, 0 are UC, 0 are
> abandoned, 0 already have enough replicas.
> 16:04:02,077 INFO RMContainerImpl:422 -
> container_1511883728609_0005_01_000002 Container Transitioned from NEW to
> ALLOCATED
> 16:04:02,077 INFO RMAuditLogger:141 - USER=nobody OPERATION=AM Allocated
> Container TARGET=SchedulerApp RESULT=SUCCESS
> APPID=application_1511883728609_0005
> CONTAINERID=container_1511883728609_0005_01_000002
> 16:04:02,077 INFO SchedulerNode:152 - Assigned container
> container_1511883728609_0005_01_000002 of capacity <memory:1024, vCores:1> on
> host ctr-e134-1499953498516-345856-01-000007.hwx.site:43216, which has 1
> containers, <memory:1024, vCores:1> used and <memory:3072, vCores:7>
> available after allocation
> 16:04:02,077 INFO AbstractContainerAllocator:89 - assignedContainer
> application attempt=appattempt_1511883728609_0005_000001
> container=container_1511883728609_0005_01_000002
> queue=org.apache.hadoop.yarn.server.resourcemanager.scheduler.capacity.allocator.RegularContainerAllocator@7a8629b9
> clusterResource=<memory:8192, vCores:16> type=OFF_SWITCH
> 16:04:02,078 INFO ParentQueue:475 - assignedContainer queue=root
> usedCapacity=0.375 absoluteUsedCapacity=0.375 used=<memory:3072, vCores:2>
> cluster=<memory:8192, vCores:16>
> 16:04:02,612 INFO NMTokenSecretManagerInRM:200 - Sending NMToken for nodeId
> : ctr-e134-1499953498516-345856-01-000007.hwx.site:43216 for container :
> container_1511883728609_0005_01_000002
> 16:04:02,613 INFO RMContainerImpl:422 -
> container_1511883728609_0005_01_000002 Container Transitioned from ALLOCATED
> to ACQUIRED
> 16:04:02,693 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job.xml
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,694 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job.xml
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,714 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/MRAppJar.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,716 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/hadoop-mapreduce-client-jobclient-2.7.3.2.6.4.0-SNAPSHOT-tests.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,718 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/other.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,719 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/myfunctions.py
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,720 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,722 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,723 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,762 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/MRAppJar.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,763 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/hadoop-mapreduce-client-jobclient-2.7.3.2.6.4.0-SNAPSHOT-tests.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,764 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/other.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,765 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/myfunctions.py
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,766 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,768 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,769 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,770 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/MRAppJar.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,771 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/hadoop-mapreduce-client-jobclient-2.7.3.2.6.4.0-SNAPSHOT-tests.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,772 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/MRAppJar.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,773 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/hadoop-mapreduce-client-jobclient-2.7.3.2.6.4.0-SNAPSHOT-tests.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,774 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/other.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,775 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/myfunctions.py
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,777 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,779 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,780 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,781 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/MRAppJar.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,782 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/nobody/target/MiniMRCluster_900807203-tmpDir/hadoop-mapreduce-client-jobclient-2.7.3.2.6.4.0-SNAPSHOT-tests.jar
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:02,901 INFO ContainerManagerImpl:810 - Start request for
> container_1511883728609_0005_01_000002 by user nobody
> 16:04:02,903 INFO ContainerManagerImpl:850 - Creating a new application
> reference for app application_1511883728609_0005
> 16:04:02,904 INFO NMAuditLogger:89 - USER=nobody IP=172.27.58.198
> OPERATION=Start Container Request TARGET=ContainerManageImpl
> RESULT=SUCCESS APPID=application_1511883728609_0005
> CONTAINERID=container_1511883728609_0005_01_000002
> 16:04:02,904 INFO ApplicationImpl:464 - Application
> application_1511883728609_0005 transitioned from NEW to INITING
> 16:04:02,904 INFO ApplicationImpl:304 - Adding
> container_1511883728609_0005_01_000002 to application
> application_1511883728609_0005
> 16:04:02,904 INFO ApplicationImpl:464 - Application
> application_1511883728609_0005 transitioned from INITING to RUNNING
> 16:04:02,905 INFO ContainerImpl:1163 - Container
> container_1511883728609_0005_01_000002 transitioned from NEW to LOCALIZING
> 16:04:02,905 INFO AuxServices:215 - Got event CONTAINER_INIT for appId
> application_1511883728609_0005
> 16:04:02,905 INFO AuxServices:215 - Got event APPLICATION_INIT for appId
> application_1511883728609_0005
> 16:04:02,905 INFO AuxServices:219 - Got APPLICATION_INIT for service
> mapreduce_shuffle
> 16:04:02,905 INFO ShuffleHandler:681 - Added token for job_1511883728609_0005
> 16:04:02,905 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip
> transitioned from INIT to DOWNLOADING
> 16:04:02,905 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py
> transitioned from INIT to DOWNLOADING
> 16:04:02,905 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip
> transitioned from INIT to DOWNLOADING
> 16:04:02,906 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job.xml
> transitioned from INIT to DOWNLOADING
> 16:04:02,906 INFO ResourceLocalizationService:784 - Downloading public
> rsrc:{
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip,
> 1511885030140, FILE, null }
> 16:04:02,989 INFO ResourceLocalizationService:784 - Downloading public
> rsrc:{
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py,
> 1511885030145, FILE, null }
> 16:04:03,017 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip
> dst=null perm=null proto=rpc
> 16:04:03,018 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib dst=null
> perm=null proto=rpc
> 16:04:03,019 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app dst=null
> perm=null proto=rpc
> 16:04:03,019 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30 dst=null
> perm=null proto=rpc
> 16:04:03,020 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo src=/user/test dst=null perm=null
> proto=rpc
> 16:04:03,020 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo src=/user dst=null perm=null
> proto=rpc
> 16:04:03,021 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo src=/ dst=null perm=null
> proto=rpc
> 16:04:03,022 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip
> dst=null perm=null proto=rpc
> 16:04:03,072 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pyspark.zip(->/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_0/filecache/18/pyspark.zip)
> transitioned from DOWNLOADING to LOCALIZED
> 16:04:03,073 INFO ResourceLocalizationService:784 - Downloading public
> rsrc:{
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip,
> 1511885030130, FILE, null }
> 16:04:03,076 INFO RMContainerImpl:422 -
> container_1511883728609_0005_01_000002 Container Transitioned from ACQUIRED
> to RUNNING
> 16:04:03,101 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py
> dst=null perm=null proto=rpc
> 16:04:03,102 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py
> dst=null perm=null proto=rpc
> 16:04:03,149 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/pi.py(->/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_3/filecache/19/pi.py)
> transitioned from DOWNLOADING to LOCALIZED
> 16:04:03,155 INFO ResourceLocalizationService:712 - Created localizer for
> container_1511883728609_0005_01_000002
> 16:04:03,171 INFO ResourceLocalizationService:1194 - Writing credentials to
> the nmPrivate file
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/nmPrivate/container_1511883728609_0005_01_000002.tokens.
> Credentials list:
> 16:04:03,183 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip
> dst=null perm=null proto=rpc
> 16:04:03,184 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip
> dst=null perm=null proto=rpc
> 16:04:03,229 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/user/test/649db0c8-4d79-4881-9a59-c3dbdd439c30/app/lib/py4j-0.9-src.zip(->/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_3/filecache/20/py4j-0.9-src.zip)
> transitioned from DOWNLOADING to LOCALIZED
> 16:04:03,248 INFO DefaultContainerExecutor:644 - Initializing user nobody
> 16:04:03,299 INFO DefaultContainerExecutor:126 - Copying from
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/nmPrivate/container_1511883728609_0005_01_000002.tokens
> to
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/usercache/nobody/appcache/application_1511883728609_0005/container_1511883728609_0005_01_000002.tokens
> 16:04:03,300 INFO DefaultContainerExecutor:133 - Localizer CWD set to
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/usercache/nobody/appcache/application_1511883728609_0005
> =
> file:/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/usercache/nobody/appcache/application_1511883728609_0005
> 16:04:03,384 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job.xml
> dst=null perm=null proto=rpc
> 16:04:03,386 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job.xml
> dst=null perm=null proto=rpc
> 16:04:03,424 INFO LocalizedResource:203 - Resource
> hdfs://localhost:38503/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job.xml(->/grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/usercache/nobody/appcache/application_1511883728609_0005/filecache/10/job.xml)
> transitioned from DOWNLOADING to LOCALIZED
> 16:04:03,424 INFO ContainerImpl:1163 - Container
> container_1511883728609_0005_01_000002 transitioned from LOCALIZING to
> LOCALIZED
> 16:04:03,474 INFO ContainerImpl:1163 - Container
> container_1511883728609_0005_01_000002 transitioned from LOCALIZED to RUNNING
> 16:04:03,474 INFO ContainersMonitorImpl:222 - Neither virutal-memory nor
> physical-memory monitoring is needed. Not running the monitor-thread
> 16:04:03,570 INFO DefaultContainerExecutor:291 - launchContainer: [bash,
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/usercache/nobody/appcache/application_1511883728609_0005/container_1511883728609_0005_01_000002/default_container_executor.sh]
> 16:04:03,635 INFO AppSchedulingInfo:220 - checking for deactivate of
> application :application_1511883728609_0005
> 16:04:04,039 INFO BlockManager:1660 - Blocks chosen but could not be
> replicated = 1; of which 1 have no target, 0 have no source, 0 are UC, 0 are
> abandoned, 0 already have enough replicas.
> 16:04:06,823 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job.split
> dst=null perm=null proto=rpc
> callerContext=mr_attempt_1511883728609_0005_m_000000_0
> 16:04:07,001 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark/0000003-171128160232232-oozie-nobo-W@spark-action
> dst=null perm=null proto=rpc
> callerContext=mr_attempt_1511883728609_0005_m_000000_0
> 16:04:07,020 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark/0000003-171128160232232-oozie-nobo-W@spark-action
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_attempt_1511883728609_0005_m_000000_0
> 16:04:07,040 INFO BlockManager:1660 - Blocks chosen but could not be
> replicated = 1; of which 1 have no target, 0 have no source, 0 are UC, 0 are
> abandoned, 0 already have enough replicas.
> 16:04:07,056 INFO StateChange:3862 - BLOCK* allocate blk_1073743270_2446,
> replicas=127.0.0.1:41272, 127.0.0.1:37352 for
> /user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark/0000003-171128160232232-oozie-nobo-W@spark-action
> 16:04:07,129 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743270_2446 src:
> /127.0.0.1:44760 dest: /127.0.0.1:41272
> 16:04:07,131 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743270_2446 src:
> /127.0.0.1:51272 dest: /127.0.0.1:37352
> 16:04:07,170 INFO clienttrace:1490 - src: /127.0.0.1:51272, dest:
> /127.0.0.1:37352, bytes: 22, op: HDFS_WRITE, cliID:
> DFSClient_attempt_1511883728609_0005_m_000000_0_1423302170_1, offset: 0,
> srvID: c355628b-02f4-4102-9823-149c581be5bc, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743270_2446, duration:
> 38575862
> 16:04:07,170 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743270_2446,
> type=LAST_IN_PIPELINE terminating
> 16:04:07,171 INFO clienttrace:1490 - src: /127.0.0.1:44760, dest:
> /127.0.0.1:41272, bytes: 22, op: HDFS_WRITE, cliID:
> DFSClient_attempt_1511883728609_0005_m_000000_0_1423302170_1, offset: 0,
> srvID: 47252ceb-afae-4640-acde-3a2b425713b6, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743270_2446, duration:
> 39157631
> 16:04:07,171 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743270_2446,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:37352] terminating
> 16:04:07,174 INFO StateChange:3755 - DIR* completeFile:
> /user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark/0000003-171128160232232-oozie-nobo-W@spark-action
> is closed by DFSClient_attempt_1511883728609_0005_m_000000_0_1423302170_1
> 16:04:07,190 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark/action.xml
> dst=null perm=null proto=rpc
> callerContext=mr_attempt_1511883728609_0005_m_000000_0
> 16:04:07,192 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark/action.xml
> dst=null perm=null proto=rpc
> callerContext=mr_attempt_1511883728609_0005_m_000000_0
> 16:04:10,040 INFO BlockManager:1660 - Blocks chosen but could not be
> replicated = 1; of which 1 have no target, 0 have no source, 0 are UC, 0 are
> abandoned, 0 already have enough replicas.
> 16:04:13,041 INFO BlockManager:1660 - Blocks chosen but could not be
> replicated = 1; of which 1 have no target, 0 have no source, 0 are UC, 0 are
> abandoned, 0 already have enough replicas.
> 16:04:16,042 INFO BlockManager:1660 - Blocks chosen but could not be
> replicated = 1; of which 1 have no target, 0 have no source, 0 are UC, 0 are
> abandoned, 0 already have enough replicas.
> 16:04:16,092 INFO ContainerManagerImpl:960 - Stopping container with
> container Id: container_1511883728609_0005_01_000002
> 16:04:16,092 INFO NMAuditLogger:89 - USER=nobody IP=172.27.58.198
> OPERATION=Stop Container Request TARGET=ContainerManageImpl
> RESULT=SUCCESS APPID=application_1511883728609_0005
> CONTAINERID=container_1511883728609_0005_01_000002
> 16:04:16,092 INFO ContainerImpl:1163 - Container
> container_1511883728609_0005_01_000002 transitioned from RUNNING to KILLING
> 16:04:16,092 INFO ContainerLaunch:541 - Cleaning up container
> container_1511883728609_0005_01_000002
> 16:04:16,111 WARN DefaultContainerExecutor:249 - Exit code from container
> container_1511883728609_0005_01_000002 is : 143
> 16:04:16,115 INFO StateChange:3862 - BLOCK* allocate blk_1073743271_2447,
> replicas=127.0.0.1:37352, 127.0.0.1:41272 for
> /tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1.jhist
> 16:04:16,119 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/COMMIT_STARTED
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,120 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743271_2447 src:
> /127.0.0.1:51420 dest: /127.0.0.1:37352
> 16:04:16,120 INFO StateChange:3755 - DIR* completeFile:
> /tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/COMMIT_STARTED
> is closed by DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:16,121 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743271_2447 src:
> /127.0.0.1:44914 dest: /127.0.0.1:41272
> 16:04:16,122 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/COMMIT_SUCCESS
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,124 INFO StateChange:3755 - DIR* completeFile:
> /tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/COMMIT_SUCCESS
> is closed by DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:16,127 INFO StateChange:4299 - BLOCK* fsync:
> /tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1.jhist
> for DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:16,137 INFO ContainerImpl:1163 - Container
> container_1511883728609_0005_01_000002 transitioned from KILLING to
> CONTAINER_CLEANEDUP_AFTER_KILL
> 16:04:16,138 INFO DefaultContainerExecutor:492 - Deleting absolute path :
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_0/usercache/nobody/appcache/application_1511883728609_0005/container_1511883728609_0005_01_000002
> 16:04:16,139 INFO DefaultContainerExecutor:492 - Deleting absolute path :
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_1/usercache/nobody/appcache/application_1511883728609_0005/container_1511883728609_0005_01_000002
> 16:04:16,141 INFO DefaultContainerExecutor:492 - Deleting absolute path :
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_2/usercache/nobody/appcache/application_1511883728609_0005/container_1511883728609_0005_01_000002
> 16:04:16,142 INFO DefaultContainerExecutor:492 - Deleting absolute path :
> /grid/0/nobody/workspace/build-support/SOURCES/oozie/sharelib/spark/target/MiniMRCluster_900807203/MiniMRCluster_900807203-localDir-nm-0_3/usercache/nobody/appcache/application_1511883728609_0005/container_1511883728609_0005_01_000002
> 16:04:16,142 INFO NMAuditLogger:89 - USER=nobody OPERATION=Container
> Finished - Killed TARGET=ContainerImpl RESULT=SUCCESS
> APPID=application_1511883728609_0005
> CONTAINERID=container_1511883728609_0005_01_000002
> 16:04:16,144 INFO ContainerImpl:1163 - Container
> container_1511883728609_0005_01_000002 transitioned from
> CONTAINER_CLEANEDUP_AFTER_KILL to DONE
> 16:04:16,144 INFO ApplicationImpl:347 - Removing
> container_1511883728609_0005_01_000002 from application
> application_1511883728609_0005
> 16:04:16,144 INFO ContainersMonitorImpl:222 - Neither virutal-memory nor
> physical-memory monitoring is needed. Not running the monitor-thread
> 16:04:16,145 INFO AuxServices:215 - Got event CONTAINER_STOP for appId
> application_1511883728609_0005
> 16:04:16,145 INFO RMContainerImpl:422 -
> container_1511883728609_0005_01_000002 Container Transitioned from RUNNING to
> COMPLETED
> 16:04:16,145 INFO RMAuditLogger:141 - USER=nobody OPERATION=AM Released
> Container TARGET=SchedulerApp RESULT=SUCCESS
> APPID=application_1511883728609_0005
> CONTAINERID=container_1511883728609_0005_01_000002
> 16:04:16,145 INFO SchedulerNode:220 - Released container
> container_1511883728609_0005_01_000002 of capacity <memory:1024, vCores:1> on
> host ctr-e134-1499953498516-345856-01-000007.hwx.site:43216, which currently
> has 0 containers, <memory:0, vCores:0> used and <memory:4096, vCores:8>
> available, release resources=true
> 16:04:16,153 INFO clienttrace:1490 - src: /127.0.0.1:44914, dest:
> /127.0.0.1:41272, bytes: 21320, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> 47252ceb-afae-4640-acde-3a2b425713b6, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743271_2447, duration:
> 30652455
> 16:04:16,153 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743271_2447,
> type=LAST_IN_PIPELINE terminating
> 16:04:16,155 INFO clienttrace:1490 - src: /127.0.0.1:51420, dest:
> /127.0.0.1:37352, bytes: 21320, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> c355628b-02f4-4102-9823-149c581be5bc, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743271_2447, duration:
> 32389529
> 16:04:16,155 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743271_2447,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:41272] terminating
> 16:04:16,156 INFO StateChange:3755 - DIR* completeFile:
> /tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1.jhist
> is closed by DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:16,158 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary_tmp
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,161 INFO StateChange:3862 - BLOCK* allocate blk_1073743272_2448,
> replicas=127.0.0.1:37352, 127.0.0.1:41272 for
> /tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary_tmp
> 16:04:16,163 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743272_2448 src:
> /127.0.0.1:51426 dest: /127.0.0.1:37352
> 16:04:16,164 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743272_2448 src:
> /127.0.0.1:44920 dest: /127.0.0.1:41272
> 16:04:16,167 INFO clienttrace:1490 - src: /127.0.0.1:44920, dest:
> /127.0.0.1:41272, bytes: 416, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> 47252ceb-afae-4640-acde-3a2b425713b6, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743272_2448, duration:
> 2041105
> 16:04:16,167 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743272_2448,
> type=LAST_IN_PIPELINE terminating
> 16:04:16,167 INFO clienttrace:1490 - src: /127.0.0.1:51426, dest:
> /127.0.0.1:37352, bytes: 416, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> c355628b-02f4-4102-9823-149c581be5bc, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743272_2448, duration:
> 2401053
> 16:04:16,168 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743272_2448,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:41272] terminating
> 16:04:16,168 INFO StateChange:3755 - DIR* completeFile:
> /tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary_tmp
> is closed by DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:16,174 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=setPermission
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary_tmp
> dst=null perm=nobody:supergroup:rwxrwx--- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,183 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1.jhist
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,184 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist_tmp
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,189 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1.jhist
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,191 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist_tmp
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,192 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1.jhist
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,194 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist_tmp
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,199 INFO StateChange:3862 - BLOCK* allocate blk_1073743273_2449,
> replicas=127.0.0.1:41272, 127.0.0.1:37352 for
> /tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist_tmp
> 16:04:16,201 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743273_2449 src:
> /127.0.0.1:44924 dest: /127.0.0.1:41272
> 16:04:16,202 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743273_2449 src:
> /127.0.0.1:51434 dest: /127.0.0.1:37352
> 16:04:16,205 INFO clienttrace:1490 - src: /127.0.0.1:51434, dest:
> /127.0.0.1:37352, bytes: 21320, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> c355628b-02f4-4102-9823-149c581be5bc, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743273_2449, duration:
> 2115381
> 16:04:16,205 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743273_2449,
> type=LAST_IN_PIPELINE terminating
> 16:04:16,205 INFO clienttrace:1490 - src: /127.0.0.1:44924, dest:
> /127.0.0.1:41272, bytes: 21320, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> 47252ceb-afae-4640-acde-3a2b425713b6, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743273_2449, duration:
> 2464775
> 16:04:16,205 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743273_2449,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:37352] terminating
> 16:04:16,206 INFO StateChange:3755 - DIR* completeFile:
> /tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist_tmp
> is closed by DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:16,207 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=setPermission
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist_tmp
> dst=null perm=nobody:supergroup:rwxrwx--- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,208 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1_conf.xml
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,209 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml_tmp
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,210 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1_conf.xml
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,210 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml_tmp
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,212 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005/job_1511883728609_0005_1_conf.xml
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,213 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=create
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml_tmp
> dst=null perm=nobody:supergroup:rw-rw-rw- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,218 INFO StateChange:3862 - BLOCK* allocate blk_1073743274_2450,
> replicas=127.0.0.1:41272, 127.0.0.1:37352 for
> /tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml_tmp
> 16:04:16,219 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743274_2450 src:
> /127.0.0.1:44928 dest: /127.0.0.1:41272
> 16:04:16,220 INFO DataNode:669 - Receiving
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743274_2450 src:
> /127.0.0.1:51438 dest: /127.0.0.1:37352
> 16:04:16,224 INFO clienttrace:1490 - src: /127.0.0.1:51438, dest:
> /127.0.0.1:37352, bytes: 141926, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> c355628b-02f4-4102-9823-149c581be5bc, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743274_2450, duration:
> 4058119
> 16:04:16,225 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743274_2450,
> type=LAST_IN_PIPELINE terminating
> 16:04:16,225 INFO clienttrace:1490 - src: /127.0.0.1:44928, dest:
> /127.0.0.1:41272, bytes: 141926, op: HDFS_WRITE, cliID:
> DFSClient_NONMAPREDUCE_-1622970731_1, offset: 0, srvID:
> 47252ceb-afae-4640-acde-3a2b425713b6, blockid:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743274_2450, duration:
> 4303796
> 16:04:16,225 INFO DataNode:1463 - PacketResponder:
> BP-1089370620-172.27.58.198-1511883710117:blk_1073743274_2450,
> type=HAS_DOWNSTREAM_IN_PIPELINE, downstreams=1:[127.0.0.1:37352] terminating
> 16:04:16,226 INFO StateChange:3755 - DIR* completeFile:
> /tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml_tmp
> is closed by DFSClient_NONMAPREDUCE_-1622970731_1
> 16:04:16,229 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=setPermission
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml_tmp
> dst=null perm=nobody:supergroup:rwxrwx--- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,234 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=rename
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary_tmp
>
> dst=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary
> perm=nobody:supergroup:rwxrwx--- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,241 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=rename
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml_tmp
>
> dst=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml
> perm=nobody:supergroup:rwxrwx--- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,243 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=rename
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist_tmp
>
> dst=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist
> perm=nobody:supergroup:rwxrwx--- proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:16,258 INFO RMAppAttemptImpl:1209 - Updating application attempt
> appattempt_1511883728609_0005_000001 with final state: FINISHING, and exit
> status: -1000
> 16:04:16,259 INFO RMAppAttemptImpl:809 -
> appattempt_1511883728609_0005_000001 State change from RUNNING to FINAL_SAVING
> 16:04:16,259 INFO RMAppImpl:1124 - Updating application
> application_1511883728609_0005 with final state: FINISHING
> 16:04:16,259 INFO RMAppImpl:779 - application_1511883728609_0005 State
> change from RUNNING to FINAL_SAVING
> 16:04:16,259 INFO RMStateStore:228 - Updating info for app:
> application_1511883728609_0005
> 16:04:16,259 INFO RMAppAttemptImpl:809 -
> appattempt_1511883728609_0005_000001 State change from FINAL_SAVING to
> FINISHING
> 16:04:16,259 INFO RMAppImpl:779 - application_1511883728609_0005 State
> change from FINAL_SAVING to FINISHING
> 16:04:17,263 INFO ApplicationMasterService:360 -
> application_1511883728609_0005 unregistered successfully.
> 16:04:17,271 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=delete
> src=/tmp/hadoop-yarn/staging/nobody/.staging/job_1511883728609_0005
> dst=null perm=null proto=rpc
> callerContext=mr_appmaster_appattempt_1511883728609_0005_000001
> 16:04:17,326 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=listStatus
> src=/tmp/hadoop-yarn/staging/history/done_intermediate dst=null
> perm=null proto=rpc
> 16:04:17,328 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=listStatus
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody dst=null
> perm=null proto=rpc
> 16:04:17,330 INFO CompletedJob:95 - Loading job: job_1511883728609_0005 from
> file:
> hdfs://localhost:38503/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist
> 16:04:17,330 INFO CompletedJob:336 - Loading history file:
> [hdfs://localhost:38503/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist]
> 16:04:17,331 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist
> dst=null perm=null proto=rpc
> 16:04:17,343 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary
> dst=null perm=null proto=rpc
> 16:04:17,344 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=open
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary
> dst=null perm=null proto=rpc
> 16:04:17,346 INFO JobSummary:421 -
> jobId=job_1511883728609_0005,submitTime=1511885033094,launchTime=1511885040566,firstMapTaskLaunchTime=1511885042919,firstReduceTaskLaunchTime=0,finishTime=1511885056125,resourcesPerMap=1024,resourcesPerReduce=0,numMaps=1,numReduces=0,user=nobody,queue=default,status=SUCCEEDED,mapSlotSeconds=13,reduceSlotSeconds=0,jobName=oozie:launcher:T\=spark:W\=testApp:A\=spark-action:ID\=0000003-171128160232232-oozie-nobo-W
> 16:04:17,346 INFO HistoryFileManager:422 - Deleting JobSummary file:
> [hdfs://localhost:38503/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary]
> 16:04:17,347 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=delete
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005.summary
> dst=null perm=null proto=rpc
> 16:04:17,349 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=getfileinfo
> src=/tmp/hadoop-yarn/staging/history/done/2017/11/28/000000 dst=null
> perm=null proto=rpc
> 16:04:17,350 INFO HistoryFileManager:1015 - Moving
> hdfs://localhost:38503/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist
> to
> hdfs://localhost:38503/tmp/hadoop-yarn/staging/history/done/2017/11/28/000000/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist
> 16:04:17,351 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=rename (options=[TO_TRASH])
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist
>
> dst=/tmp/hadoop-yarn/staging/history/done/2017/11/28/000000/job_1511883728609_0005-1511885033094-nobody-oozie%3Alauncher%3AT%3Dspark%3AW%3DtestApp%3AA%3Ds-1511885056125-1-0-SUCCEEDED-default-1511885040566.jhist
> perm=nobody:supergroup:rwxrwx--- proto=rpc
> 16:04:17,351 INFO HistoryFileManager:1015 - Moving
> hdfs://localhost:38503/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml
> to
> hdfs://localhost:38503/tmp/hadoop-yarn/staging/history/done/2017/11/28/000000/job_1511883728609_0005_conf.xml
> 16:04:17,352 INFO audit:8930 - allowed=true ugi=nobody (auth:SIMPLE)
> ip=/127.0.0.1 cmd=rename (options=[TO_TRASH])
> src=/tmp/hadoop-yarn/staging/history/done_intermediate/nobody/job_1511883728609_0005_conf.xml
>
> dst=/tmp/hadoop-yarn/staging/history/done/2017/11/28/000000/job_1511883728609_0005_conf.xml
> perm=nobody:supergroup:rwxrwx--- proto=rpc
> 16:04:17,383 INFO audit:8930 - allowed=true ugi=test (auth:PROXY) via
> nobody (auth:SIMPLE) ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark/action-data.seq
> dst=null perm=null proto=rpc
> 16:04:17,384 INFO audit:8930 - allowed=true ugi=test (auth:PROXY) via
> nobody (auth:SIMPLE) ip=/127.0.0.1 cmd=listStatus
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark
> dst=null perm=null proto=rpc
> 16:04:17,398 INFO audit:8930 - allowed=true ugi=test (auth:PROXY) via
> nobody (auth:SIMPLE) ip=/127.0.0.1 cmd=getfileinfo
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark
> dst=null perm=null proto=rpc
> 16:04:17,399 INFO audit:8930 - allowed=true ugi=test (auth:PROXY) via
> nobody (auth:SIMPLE) ip=/127.0.0.1 cmd=delete
> src=/user/test/oozie-nobo/0000003-171128160232232-oozie-nobo-W/spark-action--spark
> dst=null perm=null proto=rpc
> Standard Error
> Nov 28, 2017 3:42:06 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering org.apache.hadoop.mapreduce.v2.hs.webapp.HsWebServices as a
> root resource class
> Nov 28, 2017 3:42:06 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering
> org.apache.hadoop.mapreduce.v2.hs.webapp.JAXBContextResolver as a provider
> class
> Nov 28, 2017 3:42:06 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a
> provider class
> Nov 28, 2017 3:42:06 PM
> com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
> INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
> Nov 28, 2017 3:42:06 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.mapreduce.v2.hs.webapp.JAXBContextResolver to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:06 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:07 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.mapreduce.v2.hs.webapp.HsWebServices to
> GuiceManagedComponentProvider with the scope "PerRequest"
> Nov 28, 2017 3:42:08 PM com.google.inject.servlet.GuiceFilter setPipeline
> WARNING: Multiple Servlet injectors detected. This is a warning indicating
> that you have more than one GuiceFilter running in your web application. If
> this is deliberate, you may safely ignore this message. If this is NOT
> deliberate however, your application may not work as expected.
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering
> org.apache.hadoop.yarn.server.resourcemanager.webapp.JAXBContextResolver as a
> provider class
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering
> org.apache.hadoop.yarn.server.resourcemanager.webapp.RMWebServices as a root
> resource class
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a
> provider class
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
> INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding
> org.apache.hadoop.yarn.server.resourcemanager.webapp.JAXBContextResolver to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding
> org.apache.hadoop.yarn.server.resourcemanager.webapp.RMWebServices to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:09 PM com.google.inject.servlet.GuiceFilter setPipeline
> WARNING: Multiple Servlet injectors detected. This is a warning indicating
> that you have more than one GuiceFilter running in your web application. If
> this is deliberate, you may safely ignore this message. If this is NOT
> deliberate however, your application may not work as expected.
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering
> org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices as a root
> resource class
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a
> provider class
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering
> org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver as a
> provider class
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
> INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding
> org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:09 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices
> to GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:10 PM com.google.inject.servlet.GuiceFilter setPipeline
> WARNING: Multiple Servlet injectors detected. This is a warning indicating
> that you have more than one GuiceFilter running in your web application. If
> this is deliberate, you may safely ignore this message. If this is NOT
> deliberate however, your application may not work as expected.
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering
> org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices as a root
> resource class
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a
> provider class
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
> INFO: Registering
> org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver as a
> provider class
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
> INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding
> org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to
> GuiceManagedComponentProvider with the scope "Singleton"
> Nov 28, 2017 3:42:10 PM
> com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory
> getComponentProvider
> INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices
> to GuiceManagedComponentProvider with the scope "Singleton"
> MetaException(message:javax.jdo.JDOFatalUserException: There is no available
> StoreManager of type "rdbms". Make sure that you have put the relevant
> DataNucleus store plugin in your CLASSPATH and if defining a connection via
> JNDI or DataSource you also need to provide persistence property
> "datanucleus.storeManagerType"
> at
> org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:616)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:834)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:338)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:217)
> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at javax.jdo.JDOHelper$16.run(JDOHelper.java:1975)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.jdo.JDOHelper.invoke(JDOHelper.java:1970)
> at
> javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1177)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:814)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPMF(ObjectStore.java:495)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPersistenceManager(ObjectStore.java:524)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initializeHelper(ObjectStore.java:385)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initialize(ObjectStore.java:322)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.setConf(ObjectStore.java:283)
> at
> org.apache.hadoop.util.ReflectionUtils.setConf(ReflectionUtils.java:76)
> at
> org.apache.hadoop.util.ReflectionUtils.newInstance(ReflectionUtils.java:136)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.<init>(RawStoreProxy.java:60)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.getProxy(RawStoreProxy.java:69)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.newRawStoreForConf(HiveMetaStore.java:620)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMSForConf(HiveMetaStore.java:599)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMS(HiveMetaStore.java:593)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultDB(HiveMetaStore.java:651)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.init(HiveMetaStore.java:433)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:105)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:91)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6396)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6391)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6658)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6606)
> at org.apache.oozie.test.MiniHCatServer$1.run(MiniHCatServer.java:141)
> at java.lang.Thread.run(Thread.java:745)
> NestedThrowablesStackTrace:
> There is no available StoreManager of type "rdbms". Make sure that you have
> put the relevant DataNucleus store plugin in your CLASSPATH and if defining a
> connection via JNDI or DataSource you also need to provide persistence
> property "datanucleus.storeManagerType"
> org.datanucleus.exceptions.NucleusUserException: There is no available
> StoreManager of type "rdbms". Make sure that you have put the relevant
> DataNucleus store plugin in your CLASSPATH and if defining a connection via
> JNDI or DataSource you also need to provide persistence property
> "datanucleus.storeManagerType"
> at
> org.datanucleus.NucleusContextHelper.createStoreManagerForProperties(NucleusContextHelper.java:162)
> at
> org.datanucleus.PersistenceNucleusContextImpl.initialise(PersistenceNucleusContextImpl.java:420)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:821)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:338)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:217)
> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at javax.jdo.JDOHelper$16.run(JDOHelper.java:1975)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.jdo.JDOHelper.invoke(JDOHelper.java:1970)
> at
> javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1177)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:814)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPMF(ObjectStore.java:495)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPersistenceManager(ObjectStore.java:524)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initializeHelper(ObjectStore.java:385)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initialize(ObjectStore.java:322)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.setConf(ObjectStore.java:283)
> at
> org.apache.hadoop.util.ReflectionUtils.setConf(ReflectionUtils.java:76)
> at
> org.apache.hadoop.util.ReflectionUtils.newInstance(ReflectionUtils.java:136)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.<init>(RawStoreProxy.java:60)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.getProxy(RawStoreProxy.java:69)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.newRawStoreForConf(HiveMetaStore.java:620)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMSForConf(HiveMetaStore.java:599)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMS(HiveMetaStore.java:593)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultDB(HiveMetaStore.java:651)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.init(HiveMetaStore.java:433)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:105)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:91)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6396)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6391)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6658)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6606)
> at org.apache.oozie.test.MiniHCatServer$1.run(MiniHCatServer.java:141)
> at java.lang.Thread.run(Thread.java:745)
> ) at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:82)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:91)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6396)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6391)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6658)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6606)
> at org.apache.oozie.test.MiniHCatServer$1.run(MiniHCatServer.java:141)
> at java.lang.Thread.run(Thread.java:745)Caused by:
> MetaException(message:javax.jdo.JDOFatalUserException: There is no available
> StoreManager of type "rdbms". Make sure that you have put the relevant
> DataNucleus store plugin in your CLASSPATH and if defining a connection via
> JNDI or DataSource you also need to provide persistence property
> "datanucleus.storeManagerType"
> at
> org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:616)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:834)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:338)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:217)
> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at javax.jdo.JDOHelper$16.run(JDOHelper.java:1975)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.jdo.JDOHelper.invoke(JDOHelper.java:1970)
> at
> javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1177)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:814)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPMF(ObjectStore.java:495)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPersistenceManager(ObjectStore.java:524)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initializeHelper(ObjectStore.java:385)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initialize(ObjectStore.java:322)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.setConf(ObjectStore.java:283)
> at
> org.apache.hadoop.util.ReflectionUtils.setConf(ReflectionUtils.java:76)
> at
> org.apache.hadoop.util.ReflectionUtils.newInstance(ReflectionUtils.java:136)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.<init>(RawStoreProxy.java:60)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.getProxy(RawStoreProxy.java:69)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.newRawStoreForConf(HiveMetaStore.java:620)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMSForConf(HiveMetaStore.java:599)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMS(HiveMetaStore.java:593)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultDB(HiveMetaStore.java:651)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.init(HiveMetaStore.java:433)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:105)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:91)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6396)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6391)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6658)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6606)
> at org.apache.oozie.test.MiniHCatServer$1.run(MiniHCatServer.java:141)
> at java.lang.Thread.run(Thread.java:745)
> NestedThrowablesStackTrace:
> There is no available StoreManager of type "rdbms". Make sure that you have
> put the relevant DataNucleus store plugin in your CLASSPATH and if defining a
> connection via JNDI or DataSource you also need to provide persistence
> property "datanucleus.storeManagerType"
> org.datanucleus.exceptions.NucleusUserException: There is no available
> StoreManager of type "rdbms". Make sure that you have put the relevant
> DataNucleus store plugin in your CLASSPATH and if defining a connection via
> JNDI or DataSource you also need to provide persistence property
> "datanucleus.storeManagerType"
> at
> org.datanucleus.NucleusContextHelper.createStoreManagerForProperties(NucleusContextHelper.java:162)
> at
> org.datanucleus.PersistenceNucleusContextImpl.initialise(PersistenceNucleusContextImpl.java:420)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.freezeConfiguration(JDOPersistenceManagerFactory.java:821)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.createPersistenceManagerFactory(JDOPersistenceManagerFactory.java:338)
> at
> org.datanucleus.api.jdo.JDOPersistenceManagerFactory.getPersistenceManagerFactory(JDOPersistenceManagerFactory.java:217)
> at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at javax.jdo.JDOHelper$16.run(JDOHelper.java:1975)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.jdo.JDOHelper.invoke(JDOHelper.java:1970)
> at
> javax.jdo.JDOHelper.invokeGetPersistenceManagerFactoryOnImplementation(JDOHelper.java:1177)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:814)
> at javax.jdo.JDOHelper.getPersistenceManagerFactory(JDOHelper.java:702)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPMF(ObjectStore.java:495)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.getPersistenceManager(ObjectStore.java:524)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initializeHelper(ObjectStore.java:385)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.initialize(ObjectStore.java:322)
> at
> org.apache.hadoop.hive.metastore.ObjectStore.setConf(ObjectStore.java:283)
> at
> org.apache.hadoop.util.ReflectionUtils.setConf(ReflectionUtils.java:76)
> at
> org.apache.hadoop.util.ReflectionUtils.newInstance(ReflectionUtils.java:136)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.<init>(RawStoreProxy.java:60)
> at
> org.apache.hadoop.hive.metastore.RawStoreProxy.getProxy(RawStoreProxy.java:69)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.newRawStoreForConf(HiveMetaStore.java:620)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMSForConf(HiveMetaStore.java:599)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.getMS(HiveMetaStore.java:593)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.createDefaultDB(HiveMetaStore.java:651)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.init(HiveMetaStore.java:433)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:147)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:105)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.getProxy(RetryingHMSHandler.java:91)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6396)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.newRetryingHMSHandler(HiveMetaStore.java:6391)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6658)
> at
> org.apache.hadoop.hive.metastore.HiveMetaStore.startMetaStore(HiveMetaStore.java:6606)
> at org.apache.oozie.test.MiniHCatServer$1.run(MiniHCatServer.java:141)
> at java.lang.Thread.run(Thread.java:745)
> ) at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:212)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:105)
> at
> org.apache.hadoop.hive.metastore.RetryingHMSHandler.<init>(RetryingHMSHandler.java:78)
> ... 7 more{code}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
