Member since
03-19-2015
2
Posts
0
Kudos Received
0
Solutions
03-19-2015
10:44 AM
I am seeing the same error, and cannot figure out a solution. I am using kerberos and sentry policy file. CDH 5.3 15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO parse.ParseDriver: Parsing command: select id from firm
15/03/19 15:42:46 INFO parse.ParseDriver: Parse Completed
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=parse start=1426779766054 end=1426779766055 duration=1 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO conf.HiveAuthzConf: DefaultFS: hdfs://prodhadoop01-node-01:8020
15/03/19 15:42:46 INFO conf.HiveAuthzConf: DefaultFS: hdfs://prodhadoop01-node-01:8020
15/03/19 15:42:46 WARN mortbay.log: Using the deprecated config setting hive.sentry.server instead of sentry.hive.server
15/03/19 15:42:46 WARN mortbay.log: Using the deprecated config setting hive.sentry.provider instead of sentry.provider
15/03/19 15:42:46 WARN mortbay.log: Using the deprecated config setting hive.sentry.provider.resource instead of sentry.hive.provider.resource
15/03/19 15:42:46 INFO file.SimpleFileProviderBackend: Parsing /user/hive/sentry/sentry-provider.ini
15/03/19 15:42:46 INFO file.SimpleFileProviderBackend: Filesystem: hdfs://prodhadoop01-node-01:8020
15/03/19 15:42:46 INFO file.PolicyFiles: Opening /user/hive/sentry/sentry-provider.ini
15/03/19 15:42:46 INFO file.SimpleFileProviderBackend: Section databases needs no further processing
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Starting Semantic Analysis
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Completed phase 1 of Semantic Analysis
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Get metadata for source tables
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Get metadata for subqueries
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Get metadata for destination tables
15/03/19 15:42:46 INFO ql.Context: New scratch dir is hdfs://prodhadoop01-node-01:8020/tmp/hive-hive/hive_2015-03-19_15-42-46_054_9213739680141366916-1
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Completed getting MetaData in Semantic Analysis
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Set stats collection dir : hdfs://prodhadoop01-node-01:8020/tmp/hive-hive/hive_2015-03-19_15-42-46_054_9213739680141366916-1/-ext-10002
15/03/19 15:42:46 INFO ppd.OpProcFactory: Processing for FS(27)
15/03/19 15:42:46 INFO ppd.OpProcFactory: Processing for SEL(26)
15/03/19 15:42:46 INFO ppd.OpProcFactory: Processing for TS(25)
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=partition-retrieving from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=partition-retrieving start=1426779766137 end=1426779766137 duration=0 from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner>
15/03/19 15:42:46 INFO physical.MetadataOnlyOptimizer: Looking for table scans where optimization is applicable
15/03/19 15:42:46 INFO physical.MetadataOnlyOptimizer: Found 0 metadata only table scans
15/03/19 15:42:46 INFO parse.SemanticAnalyzer: Completed plan generation
15/03/19 15:42:46 INFO ql.Driver: Semantic Analysis Completed
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=semanticAnalyze start=1426779766055 end=1426779766138 duration=83 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO exec.ListSinkOperator: Initializing Self 28 OP
15/03/19 15:42:46 INFO exec.ListSinkOperator: Operator 28 OP initialized
15/03/19 15:42:46 INFO exec.ListSinkOperator: Initialization Done 28 OP
15/03/19 15:42:46 INFO ql.Driver: Returning Hive schema: Schema(fieldSchemas:[FieldSchema(name:id, type:int, comment:null)], properties:null)
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=compile start=1426779766054 end=1426779766139 duration=85 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=TimeToSubmit from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=acquireReadWriteLocks from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO lockmgr.DummyTxnManager: Creating lock manager of type org.apache.hadoop.hive.ql.lockmgr.zookeeper.ZooKeeperHiveLockManager
15/03/19 15:42:46 INFO zookeeper.ZooKeeper: Initiating client connection, connectString=prodhadoop01-node-01:2181,prodhadoop01-node-04:2181,prodhadoop01-node-05:2181 sessionTimeout=600000 watcher=org.apache.hadoop.hive.ql.lockmgr.zookeeper.ZooKeeperHiveLockManager$DummyWatcher@1a65511f
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=acquireReadWriteLocks start=1426779766141 end=1426779766200 duration=59 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO ql.Driver: Starting command: select id from firm
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=PreHook.org.apache.sentry.binding.hive.HiveAuthzBindingPreExecHook from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=PreHook.org.apache.sentry.binding.hive.HiveAuthzBindingPreExecHook start=1426779766200 end=1426779766200 duration=0 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO ql.Driver: Total jobs = 1
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=TimeToSubmit start=1426779766141 end=1426779766201 duration=60 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=task.MAPRED.Stage-1 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:42:46 INFO ql.Driver: Launching Job 1 out of 1
15/03/19 15:42:46 INFO exec.Task: Number of reduce tasks is set to 0 since there's no reduce operator
15/03/19 15:42:46 INFO ql.Context: New scratch dir is hdfs://prodhadoop01-node-01:8020/tmp/hive-hive/hive_2015-03-19_15-42-46_054_9213739680141366916-6
15/03/19 15:42:46 INFO mr.ExecDriver: Using org.apache.hadoop.hive.ql.io.CombineHiveInputFormat
15/03/19 15:42:46 INFO mr.ExecDriver: adding libjars: file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hive/lib/hive-hbase-handler-0.13.1-cdh5.2.4.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/lib/htrace-core.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/lib/htrace-core-2.04.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/hbase-hadoop-compat.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/hbase-server.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/hbase-common.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/hbase-protocol.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/hbase-hadoop2-compat.jar,file:///opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hbase/hbase-client.jar
15/03/19 15:42:46 INFO exec.Utilities: Processing alias firm
15/03/19 15:42:46 INFO exec.Utilities: Adding input file hdfs://prodhadoop01-node-01:8020/user/hive/warehouse/pod03_ema.db/firm
15/03/19 15:42:46 INFO exec.Utilities: Content Summary not cached for hdfs://prodhadoop01-node-01:8020/user/hive/warehouse/pod03_ema.db/firm
15/03/19 15:42:46 INFO ql.Context: New scratch dir is hdfs://prodhadoop01-node-01:8020/tmp/hive-hive/hive_2015-03-19_15-42-46_054_9213739680141366916-6
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=serializePlan from=org.apache.hadoop.hive.ql.exec.Utilities>
15/03/19 15:42:46 INFO exec.Utilities: Serializing MapWork via kryo
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=serializePlan start=1426779766217 end=1426779766247 duration=30 from=org.apache.hadoop.hive.ql.exec.Utilities>
15/03/19 15:42:46 INFO client.RMProxy: Connecting to ResourceManager at prodhadoop01-node-01/10.0.2.156:8032
15/03/19 15:42:46 INFO client.RMProxy: Connecting to ResourceManager at prodhadoop01-node-01/10.0.2.156:8032
15/03/19 15:42:46 INFO exec.Utilities: No plan file found: hdfs://prodhadoop01-node-01:8020/tmp/hive-hive/hive_2015-03-19_15-42-46_054_9213739680141366916-6/-mr-10004/2c0837da-5c34-4f5f-8685-8aaa2712d2dc/reduce.xml
15/03/19 15:42:46 INFO hdfs.DFSClient: Created HDFS_DELEGATION_TOKEN token 187 for hive on 10.0.2.156:8020
15/03/19 15:42:46 INFO security.TokenCache: Got dt for hdfs://prodhadoop01-node-01:8020; Kind: HDFS_DELEGATION_TOKEN, Service: 10.0.2.156:8020, Ident: (HDFS_DELEGATION_TOKEN token 187 for hive)
15/03/19 15:42:46 WARN mapreduce.JobSubmitter: Hadoop command-line option parsing not performed. Implement the Tool interface and execute your application with ToolRunner to remedy this.
15/03/19 15:42:46 INFO log.PerfLogger: <PERFLOG method=getSplits from=org.apache.hadoop.hive.ql.io.CombineHiveInputFormat>
15/03/19 15:42:46 INFO io.CombineHiveInputFormat: CombineHiveInputSplit creating pool for hdfs://prodhadoop01-node-01:8020/user/hive/warehouse/pod03_ema.db/firm; using filter path hdfs://prodhadoop01-node-01:8020/user/hive/warehouse/pod03_ema.db/firm
15/03/19 15:42:46 INFO input.FileInputFormat: Total input paths to process : 4
15/03/19 15:42:46 INFO input.CombineFileInputFormat: DEBUG: Terminated node allocation with : CompletedNodes: 4, size left: 0
15/03/19 15:42:46 INFO io.CombineHiveInputFormat: number of splits 2
15/03/19 15:42:46 INFO log.PerfLogger: </PERFLOG method=getSplits start=1426779766808 end=1426779766821 duration=13 from=org.apache.hadoop.hive.ql.io.CombineHiveInputFormat>
15/03/19 15:42:46 INFO mapreduce.JobSubmitter: number of splits:2
15/03/19 15:42:46 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_1426777422106_0005
15/03/19 15:42:46 INFO mapreduce.JobSubmitter: Kind: HDFS_DELEGATION_TOKEN, Service: 10.0.2.156:8020, Ident: (HDFS_DELEGATION_TOKEN token 187 for hive)
15/03/19 15:42:47 INFO impl.YarnClientImpl: Submitted application application_1426777422106_0005
15/03/19 15:42:47 INFO mapreduce.Job: The url to track the job: https://prodhadoop01-node-01:8090/proxy/application_1426777422106_0005/
15/03/19 15:42:47 INFO exec.Task: Starting Job = job_1426777422106_0005, Tracking URL = https://prodhadoop01-node-01:8090/proxy/application_1426777422106_0005/
15/03/19 15:42:47 INFO exec.Task: Kill Command = /opt/cloudera/parcels/CDH-5.2.4-1.cdh5.2.4.p0.3/lib/hadoop/bin/hadoop job -kill job_1426777422106_0005
15/03/19 15:43:01 INFO exec.Task: Hadoop job information for Stage-1: number of mappers: 0; number of reducers: 0
15/03/19 15:43:01 WARN mapreduce.Counters: Group org.apache.hadoop.mapred.Task$Counter is deprecated. Use org.apache.hadoop.mapreduce.TaskCounter instead
15/03/19 15:43:01 INFO exec.Task: 2015-03-19 15:43:01,246 Stage-1 map = 0%, reduce = 0%
15/03/19 15:43:01 WARN mapreduce.Counters: Group org.apache.hadoop.mapred.Task$Counter is deprecated. Use org.apache.hadoop.mapreduce.TaskCounter instead
15/03/19 15:43:01 ERROR exec.Task: Ended Job = job_1426777422106_0005 with errors
15/03/19 15:43:01 INFO impl.YarnClientImpl: Killed application application_1426777422106_0005
15/03/19 15:43:01 ERROR ql.Driver: FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask
15/03/19 15:43:01 INFO log.PerfLogger: </PERFLOG method=Driver.execute start=1426779766200 end=1426779781272 duration=15072 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:43:01 INFO ql.Driver: MapReduce Jobs Launched:
15/03/19 15:43:01 WARN mapreduce.Counters: Group FileSystemCounters is deprecated. Use org.apache.hadoop.mapreduce.FileSystemCounter instead
15/03/19 15:43:01 INFO ql.Driver: Stage-Stage-1: HDFS Read: 0 HDFS Write: 0 FAIL
15/03/19 15:43:01 INFO ql.Driver: Total MapReduce CPU Time Spent: 0 msec
15/03/19 15:43:01 INFO log.PerfLogger: <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:43:01 INFO ZooKeeperHiveLockManager: about to release lock for pod03_ema/firm
15/03/19 15:43:01 INFO ZooKeeperHiveLockManager: about to release lock for pod03_ema
15/03/19 15:43:01 INFO log.PerfLogger: </PERFLOG method=releaseLocks start=1426779781273 end=1426779781289 duration=16 from=org.apache.hadoop.hive.ql.Driver>
15/03/19 15:43:01 ERROR operation.Operation: Error running hive query:
org.apache.hive.service.cli.HiveSQLException: Error while processing statement: FAILED: Execution Error, return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapRedTask
at org.apache.hive.service.cli.operation.SQLOperation.runInternal(SQLOperation.java:147)
at org.apache.hive.service.cli.operation.SQLOperation.access$000(SQLOperation.java:69)
at org.apache.hive.service.cli.operation.SQLOperation$1$1.run(SQLOperation.java:200)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:415)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1614)
at org.apache.hadoop.hive.shims.HadoopShimsSecure.doAs(HadoopShimsSecure.java:502)
at org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:213)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
... View more