[
https://issues.apache.org/jira/browse/HIVE-13017?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sushanth Sowmyan updated HIVE-13017:
------------------------------------
Attachment: HIVE-13017.2.patch
Updated patch to make sure it polls default fs as well.
> Child process of HiveServer2 fails to get delegation token from non default
> FileSystem
> --------------------------------------------------------------------------------------
>
> Key: HIVE-13017
> URL: https://issues.apache.org/jira/browse/HIVE-13017
> Project: Hive
> Issue Type: Bug
> Components: Authentication
> Affects Versions: 1.2.1
> Environment: Secure
> Reporter: Takahiko Saito
> Assignee: Sushanth Sowmyan
> Attachments: HIVE-13017.2.patch, HIVE-13017.patch
>
>
> The following query fails, when Azure Filesystem is used as default file
> system, and HDFS is used for intermediate data.
> {noformat}
> >>> create temporary table s10k stored as orc as select * from studenttab10k;
> >>> create temporary table v10k as select * from votertab10k;
> >>> select registration
> from s10k s join v10k v
> on (s.name = v.name) join studentparttab30k p
> on (p.name = v.name)
> where s.age < 25 and v.age < 25 and p.age < 25;
> ERROR : Execution failed with exit status: 2
> ERROR : Obtaining error information
> ERROR :
> Task failed!
> Task ID:
> Stage-5
> Logs:
> ERROR : /var/log/hive/hiveServer2.log
> Error: Error while processing statement: FAILED: Execution Error, return code
> 2 from org.apache.hadoop.hive.ql.exec.mr.MapredLocalTask (state=08S01,code=2)
> Aborting command set because "force" is false and command failed: "select
> registration
> from s10k s join v10k v
> on (s.name = v.name) join studentparttab30k p
> on (p.name = v.name)
> where s.age < 25 and v.age < 25 and p.age < 25;"
> Closing: 0:
> jdbc:hive2://zk2-hs21-h.hdinsight.net:2181/;serviceDiscoveryMode=zooKeeper;zooKeeperNamespace=hiveserver2;principal=hive/_h...@hdinsight.net;transportMode=http;httpPath=cliservice
> hiveServer2.log shows:
> 2016-02-02 18:04:34,182 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,199 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=TimeToSubmit from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,212 INFO [HiveServer2-HttpHandler-Pool: Thread-55]:
> thrift.ThriftHttpServlet (ThriftHttpServlet.java:doPost(127)) - Could not
> validate cookie sent, will try to generate a new cookie
> 2016-02-02 18:04:34,213 INFO [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (Driver.java:checkConcurrency(168)) - Concurrency mode is disabled,
> not creating a lock manager
> 2016-02-02 18:04:34,219 INFO [HiveServer2-HttpHandler-Pool: Thread-55]:
> thrift.ThriftHttpServlet (ThriftHttpServlet.java:doKerberosAuth(352)) -
> Failed to authenticate with http/_HOST kerberos principal, trying with
> hive/_HOST kerberos principal
> 2016-02-02 18:04:34,219 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,225 INFO [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (Driver.java:execute(1390)) - Setting caller context to query id
> hive_20160202180429_7ffff6ab-64d6-4c89-88b0-6355cc5acbd0
> 2016-02-02 18:04:34,226 INFO [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (Driver.java:execute(1393)) - Starting
> command(queryId=hive_20160202180429_7ffff6ab-64d6-4c89-88b0-6355cc5acbd0):
> select registration
> from s10k s join v10k v
> on (s.name = v.name) join studentparttab30k p
> on (p.name = v.name)
> where s.age < 25 and v.age < 25 and p.age < 25
> 2016-02-02 18:04:34,228 INFO [HiveServer2-Background-Pool: Thread-517]:
> hooks.ATSHook (ATSHook.java:<init>(90)) - Created ATS Hook
> 2016-02-02 18:04:34,229 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=PreHook.org.apache.hadoop.hive.ql.hooks.ATSHook
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,237 INFO [HiveServer2-HttpHandler-Pool: Thread-55]:
> thrift.ThriftHttpServlet (ThriftHttpServlet.java:doPost(169)) - Cookie added
> for clientUserName hrt_qa
> 2016-02-02 18:04:34,238 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG
> method=PreHook.org.apache.hadoop.hive.ql.hooks.ATSHook start=1454436274229
> end=1454436274238 duration=9 from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,239 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=PreHook.org.apache.hadoop.hive.ql.security.authorization.plugin.DisallowTransformHook
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,240 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG
> method=PreHook.org.apache.hadoop.hive.ql.security.authorization.plugin.DisallowTransformHook
> start=1454436274239 end=1454436274240 duration=1
> from=org.apache.hadoop.hive.ql.Driver>
> Query ID = hive_20160202180429_7ffff6ab-64d6-4c89-88b0-6355cc5acbd0
> 2016-02-02 18:04:34,242 INFO [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (SessionState.java:printInfo(923)) - Query ID =
> hive_20160202180429_7ffff6ab-64d6-4c89-88b0-6355cc5acbd0
> Total jobs = 1
> 2016-02-02 18:04:34,243 INFO [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (SessionState.java:printInfo(923)) - Total jobs = 1
> 2016-02-02 18:04:34,245 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG
> method=TimeToSubmit start=1454436274199 end=1454436274245 duration=46
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,246 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG method=runTasks
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,247 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=task.MAPREDLOCAL.Stage-5 from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:34,258 INFO [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (Driver.java:launchTask(1718)) - Starting task
> [Stage-5:MAPREDLOCAL] in serial mode
> 2016-02-02 18:04:34,280 INFO [HiveServer2-Background-Pool: Thread-517]:
> mr.MapredLocalTask (MapredLocalTask.java:executeInChildVM(158)) - Generating
> plan file
> file:/tmp/hive/916e3dbb-a10d-4888-a063-52fb058ea421/hive_2016-02-02_18-04-29_153_625340340820843828-4/-local-10006/plan.xml
> 2016-02-02 18:04:34,288 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=serializePlan from=org.apache.hadoop.hive.ql.exec.Utilities>
> 2016-02-02 18:04:34,289 INFO [HiveServer2-Background-Pool: Thread-517]:
> exec.Utilities (Utilities.java:serializePlan(1028)) - Serializing
> MapredLocalWork via kryo
> 2016-02-02 18:04:34,290 INFO [ATS Logger 0]: hooks.ATSHook
> (ATSHook.java:createPreHookEvent(158)) - Received pre-hook notification for
> :hive_20160202180429_7ffff6ab-64d6-4c89-88b0-6355cc5acbd0
> 2016-02-02 18:04:34,358 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG
> method=serializePlan start=1454436274288 end=1454436274358 duration=70
> from=org.apache.hadoop.hive.ql.exec.Utilities>
> 2016-02-02 18:04:34,737 INFO [HiveServer2-Background-Pool: Thread-517]:
> mr.MapredLocalTask (MapredLocalTask.java:executeInChildVM(287)) - Executing:
> /usr/hdp/2.4.1.0-170/hadoop/bin/hadoop jar
> /usr/hdp/2.4.1.0-170/hive/lib/hive-common-1.2.1000.2.4.1.0-170.jar
> org.apache.hadoop.hive.ql.exec.mr.ExecDriver -localtask -plan
> file:/tmp/hive/916e3dbb-a10d-4888-a063-52fb058ea421/hive_2016-02-02_18-04-29_153_625340340820843828-4/-local-10006/plan.xml
> -jobconffile
> file:/tmp/hive/916e3dbb-a10d-4888-a063-52fb058ea421/hive_2016-02-02_18-04-29_153_625340340820843828-4/-local-10007/jobconf.xml
> WARNING: Use "yarn jar" to launch YARN applications.
> 2016-02-02 18:04:37,450 INFO
> [org.apache.ranger.audit.queue.AuditBatchQueue0]: provider.BaseAuditHandler
> (BaseAuditHandler.java:logStatus(312)) - Audit Status Log:
> name=hiveServer2.async.summary.batch.solr, interval=01:21.012 minutes,
> events=2, succcessCount=2, totalEvents=4, totalSuccessCount=4
> Execution log at:
> /tmp/hive/hive_20160202180429_7ffff6ab-64d6-4c89-88b0-6355cc5acbd0.log
> 2016-02-02 18:04:39,248 INFO [HiveServer2-HttpHandler-Pool: Thread-55]:
> thrift.ThriftHttpServlet (ThriftHttpServlet.java:doPost(127)) - Could not
> validate cookie sent, will try to generate a new cookie
> 2016-02-02 18:04:39,254 INFO [HiveServer2-HttpHandler-Pool: Thread-55]:
> thrift.ThriftHttpServlet (ThriftHttpServlet.java:doKerberosAuth(352)) -
> Failed to authenticate with http/_HOST kerberos principal, trying with
> hive/_HOST kerberos principal
> 2016-02-02 18:04:39,261 INFO [HiveServer2-HttpHandler-Pool: Thread-55]:
> thrift.ThriftHttpServlet (ThriftHttpServlet.java:doPost(169)) - Cookie added
> for clientUserName hrt_qa
> 2016-02-02 18:04:40 Starting to launch local task to process map join;
> maximum memory = 477102080
> Execution failed with exit status: 2
> 2016-02-02 18:04:43,728 ERROR [HiveServer2-Background-Pool: Thread-517]:
> exec.Task (SessionState.java:printError(932)) - Execution failed with exit
> status: 2
> Obtaining error information
> 2016-02-02 18:04:43,730 ERROR [HiveServer2-Background-Pool: Thread-517]:
> exec.Task (SessionState.java:printError(932)) - Obtaining error information
> Task failed!
> Task ID:
> Stage-5
> Logs:
> 2016-02-02 18:04:43,730 ERROR [HiveServer2-Background-Pool: Thread-517]:
> exec.Task (SessionState.java:printError(932)) -
> Task failed!
> Task ID:
> Stage-5
> Logs:
> /var/log/hive/hiveServer2.log
> 2016-02-02 18:04:43,732 ERROR [HiveServer2-Background-Pool: Thread-517]:
> exec.Task (SessionState.java:printError(932)) - /var/log/hive/hiveServer2.log
> 2016-02-02 18:04:43,732 ERROR [HiveServer2-Background-Pool: Thread-517]:
> mr.MapredLocalTask (MapredLocalTask.java:executeInChildVM(307)) - Execution
> failed with exit status: 2
> 2016-02-02 18:04:43,733 INFO [HiveServer2-Background-Pool: Thread-517]:
> hooks.ATSHook (ATSHook.java:<init>(90)) - Created ATS Hook
> 2016-02-02 18:04:43,734 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=FailureHook.org.apache.hadoop.hive.ql.hooks.ATSHook
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:43,736 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG
> method=FailureHook.org.apache.hadoop.hive.ql.hooks.ATSHook
> start=1454436283734 end=1454436283736 duration=2
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:43,736 INFO [ATS Logger 0]: hooks.ATSHook
> (ATSHook.java:createPostHookEvent(193)) - Received post-hook notification for
> :hive_20160202180429_7ffff6ab-64d6-4c89-88b0-6355cc5acbd0
> FAILED: Execution Error, return code 2 from
> org.apache.hadoop.hive.ql.exec.mr.MapredLocalTask
> 2016-02-02 18:04:43,757 ERROR [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (SessionState.java:printError(932)) - FAILED: Execution Error,
> return code 2 from org.apache.hadoop.hive.ql.exec.mr.MapredLocalTask
> 2016-02-02 18:04:43,758 INFO [HiveServer2-Background-Pool: Thread-517]:
> ql.Driver (Driver.java:execute(1621)) - Resetting the caller context to
> HIVE_SSN_ID:916e3dbb-a10d-4888-a063-52fb058ea421
> 2016-02-02 18:04:43,759 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG
> method=Driver.execute start=1454436274219 end=1454436283759 duration=9540
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:43,760 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogBegin(135)) - <PERFLOG
> method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:43,761 INFO [HiveServer2-Background-Pool: Thread-517]:
> log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG
> method=releaseLocks start=1454436283760 end=1454436283761 duration=1
> from=org.apache.hadoop.hive.ql.Driver>
> 2016-02-02 18:04:43,766 ERROR [HiveServer2-Background-Pool: Thread-517]:
> operation.Operation (SQLOperation.java:run(209)) - 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.MapredLocalTask
> at
> org.apache.hive.service.cli.operation.Operation.toSQLException(Operation.java:315)
> at
> org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:156)
> at
> org.apache.hive.service.cli.operation.SQLOperation.access$100(SQLOperation.java:71)
> at
> org.apache.hive.service.cli.operation.SQLOperation$1$1.run(SQLOperation.java:206)
> 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:1657)
> at
> org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:218)
> 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)
> hive Configs can be viewed from
> http://qelog.hortonworks.com/log/hs21-hbs24-1454382123/artifacts/tmpModifyConfDir_1454394513592/
> Attachments
> Drop files to attach, or browse.
> Add LinkIssue Links
> relates to
> Bug - A problem which impairs or prevents the functions of the product.
> HIVE-739 webhcat tests failing in HDInsight secure cluster throwing
> NullPointerException Blocker - Blocks development and/or testing work,
> production could not run. RESOLVED
> Activity
> All
> Comments
> Work Log
> History
> Activity
> Ascending order - Click to sort in descending order
> Permalink Edit Delete
> tsaito Takahiko Saito added a comment - 3 days ago
> The test passes via hive CLI and explain shows:
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> explain select registration
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> from s10k s join v10k v
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> on (s.name = v.name) join
> studentparttab30k p
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> on (p.name = v.name)
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> where s.age < 25 and v.age <
> 25 and p.age < 25;
> +--------------------------------------------------------------------------------------------------------------+--+
> | Explain
> |
> +--------------------------------------------------------------------------------------------------------------+--+
> | STAGE DEPENDENCIES:
> |
> | Stage-5 is a root stage
> |
> | Stage-4 depends on stages: Stage-5
> |
> | Stage-0 depends on stages: Stage-4
> |
> |
> |
> | STAGE PLANS:
> |
> | Stage: Stage-5
> |
> | Map Reduce Local Work
> |
> | Alias -> Map Local Tables:
> |
> | s
> |
> | Fetch Operator
> |
> | limit: -1
> |
> | v
> |
> | Fetch Operator
> |
> | limit: -1
> |
> | Alias -> Map Local Operator Tree:
> |
> | s
> |
> | TableScan
> |
> | alias: s
> |
> | filterExpr: (name is not null and (age < 25)) (type: boolean)
> |
> | Statistics: Num rows: 459 Data size: 47777 Basic stats:
> COMPLETE Column stats: NONE |
> | Filter Operator
> |
> | predicate: (name is not null and (age < 25)) (type: boolean)
> |
> | Statistics: Num rows: 76 Data size: 7910 Basic stats:
> COMPLETE Column stats: NONE |
> | HashTable Sink Operator
> |
> | keys:
> |
> | 0 name (type: string)
> |
> | 1 name (type: string)
> |
> | 2 name (type: string)
> |
> | v
> |
> | TableScan
> |
> | alias: v
> |
> | filterExpr: (name is not null and (age < 25)) (type: boolean)
> |
> | Statistics: Num rows: 1653 Data size: 337233 Basic stats:
> COMPLETE Column stats: NONE |
> | Filter Operator
> |
> | predicate: (name is not null and (age < 25)) (type: boolean)
> |
> | Statistics: Num rows: 275 Data size: 56103 Basic stats:
> COMPLETE Column stats: NONE |
> | HashTable Sink Operator
> |
> | keys:
> |
> | 0 name (type: string)
> |
> | 1 name (type: string)
> |
> | 2 name (type: string)
> |
> |
> |
> | Stage: Stage-4
> |
> | Map Reduce
> |
> | Map Operator Tree:
> |
> | TableScan
> |
> | alias: p
> |
> | filterExpr: (name is not null and (age < 25)) (type: boolean)
> |
> | Statistics: Num rows: 30000 Data size: 627520 Basic stats:
> COMPLETE Column stats: COMPLETE |
> | Filter Operator
> |
> | predicate: (name is not null and (age < 25)) (type: boolean)
> |
> | Statistics: Num rows: 10000 Data size: 1010000 Basic stats:
> COMPLETE Column stats: COMPLETE |
> | Map Join Operator
> |
> | condition map:
> |
> | Inner Join 0 to 1
> |
> | Inner Join 1 to 2
> |
> | keys:
> |
> | 0 name (type: string)
> |
> | 1 name (type: string)
> |
> | 2 name (type: string)
> |
> | outputColumnNames: _col8
> |
> | Statistics: Num rows: 22000 Data size: 2222000 Basic stats:
> COMPLETE Column stats: NONE |
> | Select Operator
> |
> | expressions: _col8 (type: string)
> |
> | outputColumnNames: _col0
> |
> | Statistics: Num rows: 22000 Data size: 2222000 Basic
> stats: COMPLETE Column stats: NONE |
> | File Output Operator
> |
> | compressed: false
> |
> | Statistics: Num rows: 22000 Data size: 2222000 Basic
> stats: COMPLETE Column stats: NONE |
> | table:
> |
> | input format:
> org.apache.hadoop.mapred.TextInputFormat |
> | output format:
> org.apache.hadoop.hive.ql.io.HiveIgnoreKeyTextOutputFormat |
> | serde:
> org.apache.hadoop.hive.serde2.lazy.LazySimpleSerDe
> |
> | Local Work:
> |
> | Map Reduce Local Work
> |
> |
> |
> | Stage: Stage-0
> |
> | Fetch Operator
> |
> | limit: -1
> |
> | Processor Tree:
> |
> | ListSink
> |
> |
> |
> +--------------------------------------------------------------------------------------------------------------+--+
> 83 rows selected (2.473 seconds)
> Permalink Edit Delete
> tsaito Takahiko Saito added a comment - 3 days ago
> emptablemisc_8 also fails with the same error:
> >>> create temporary table temp1 as select * from votertab10k;
> >>> select *
> from studenttab10k s
> where s.name not in
> (select name from temp1);
> INFO : Number of reduce tasks determined at compile time: 1
> INFO : In order to change the average load for a reducer (in bytes):
> INFO : set hive.exec.reducers.bytes.per.reducer=<number>
> INFO : In order to limit the maximum number of reducers:
> INFO : set hive.exec.reducers.max=<number>
> INFO : In order to set a constant number of reducers:
> INFO : set mapreduce.job.reduces=<number>
> INFO : number of splits:1
> INFO : Submitting tokens for job: job_1454394534358_0164
> INFO : Kind: HDFS_DELEGATION_TOKEN, Service: 10.0.0.36:8020, Ident:
> (HDFS_DELEGATION_TOKEN token 246 for hrt_qa)
> INFO : The url to track the job:
> http://hn0-hs21-h.hdinsight.net:8088/proxy/application_1454394534358_0164/
> INFO : Starting Job = job_1454394534358_0164, Tracking URL =
> http://hn0-hs21-h.hdinsight.net:8088/proxy/application_1454394534358_0164/
> INFO : Kill Command = /usr/hdp/2.4.1.0-170/hadoop/bin/hadoop job -kill
> job_1454394534358_0164
> INFO : Hadoop job information for Stage-4: number of mappers: 1; number of
> reducers: 1
> INFO : 2016-02-02 10:11:02,367 Stage-4 map = 0%, reduce = 0%
> INFO : 2016-02-02 10:11:26,060 Stage-4 map = 100%, reduce = 0%, Cumulative
> CPU 5.48 sec
> INFO : 2016-02-02 10:11:39,024 Stage-4 map = 100%, reduce = 100%,
> Cumulative CPU 11.18 sec
> INFO : MapReduce Total cumulative CPU time: 11 seconds 180 msec
> INFO : Ended Job = job_1454394534358_0164
> INFO : Stage-9 is selected by condition resolver.
> INFO : Stage-1 is filtered out by condition resolver.
> ERROR : Execution failed with exit status: 2
> ERROR : Obtaining error information
> ERROR :
> Task failed!
> Task ID:
> Stage-9
> Logs:
> ERROR : /var/log/hive/hiveServer2.log
> INFO : Number of reduce tasks determined at compile time: 1
> INFO : In order to change the average load for a reducer (in bytes):
> INFO : set hive.exec.reducers.bytes.per.reducer=<number>
> INFO : In order to limit the maximum number of reducers:
> INFO : set hive.exec.reducers.max=<number>
> INFO : In order to set a constant number of reducers:
> INFO : set mapreduce.job.reduces=<number>
> INFO : number of splits:2
> INFO : Submitting tokens for job: job_1454394534358_0169
> INFO : Kind: HDFS_DELEGATION_TOKEN, Service: 10.0.0.36:8020, Ident:
> (HDFS_DELEGATION_TOKEN token 252 for hrt_qa)
> INFO : The url to track the job:
> http://hn0-hs21-h.hdinsight.net:8088/proxy/application_1454394534358_0169/
> INFO : Starting Job = job_1454394534358_0169, Tracking URL =
> http://hn0-hs21-h.hdinsight.net:8088/proxy/application_1454394534358_0169/
> INFO : Kill Command = /usr/hdp/2.4.1.0-170/hadoop/bin/hadoop job -kill
> job_1454394534358_0169
> INFO : Hadoop job information for Stage-1: number of mappers: 2; number of
> reducers: 1
> INFO : 2016-02-02 10:16:38,027 Stage-1 map = 0%, reduce = 0%
> INFO : 2016-02-02 10:16:52,498 Stage-1 map = 50%, reduce = 0%, Cumulative
> CPU 3.8 sec
> INFO : 2016-02-02 10:16:53,566 Stage-1 map = 100%, reduce = 0%, Cumulative
> CPU 9.94 sec
> INFO : 2016-02-02 10:17:16,202 Stage-1 map = 100%, reduce = 100%,
> Cumulative CPU 17.04 sec
> INFO : MapReduce Total cumulative CPU time: 17 seconds 40 msec
> INFO : Ended Job = job_1454394534358_0169
> ERROR : Execution failed with exit status: 2
> ERROR : Obtaining error information
> ERROR :
> Task failed!
> Task ID:
> Stage-8
> Logs:
> ERROR : /var/log/hive/hiveServer2.log
> Error: Error while processing statement: FAILED: Execution Error, return code
> 2 from org.apache.hadoop.hive.ql.exec.mr.MapredLocalTask (state=08S01,code=2)
> Aborting command set because "force" is false and command failed: "select *
> from studenttab10k s
> where s.name not in
> (select name from temp1);"
> Closing: 0:
> jdbc:hive2://zk2-hs21-h.hdinsight.net:2181/;serviceDiscoveryMode=zooKeeper;zooKeeperNamespace=hiveserver2;principal=hive/_h...@hdinsight.net;transportMode=http;httpPath=cliservice
> Its app log can be viewed at
> http://qelog.hortonworks.com/log/hs21-hbs24-1454382123/app-logs/application_1454394534358_0169.log
> Permalink Edit Delete
> tsaito Takahiko Saito added a comment - 3 days ago
> The query works without 'temporary table':
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> select registration from
> studenttab10k s join votertab10k v
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> on (s.name = v.name) join
> studentparttab30k p
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> on (p.name = v.name)
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> where s.age < 25 and v.age <
> 25 and p.age < 25;
> Permalink Edit Delete
> tsaito Takahiko Saito added a comment - 3 days ago
> More info about temporary table:
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> describe formatted s10k;
> +-------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------+-----------------------+--+
> | col_name |
> data_type
> | comment |
> +-------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------+-----------------------+--+
> | # col_name | data_type
>
> | comment |
> | | NULL
>
> | NULL |
> | name | string
>
> | |
> | age | int
>
> | |
> | gpa | double
>
> | |
> | | NULL
>
> | NULL |
> | # Detailed Table Information | NULL
>
> | NULL |
> | Database: | default
>
> | NULL |
> | Owner: | hrt_qa
>
> | NULL |
> | CreateTime: | Tue Feb 02 23:02:31 UTC 2016
>
> | NULL |
> | LastAccessTime: | UNKNOWN
>
> | NULL |
> | Protect Mode: | None
>
> | NULL |
> | Retention: | 0
>
> | NULL |
> | Location: |
> hdfs://hn0-hs21-h.hdinsight.net:8020/tmp/hive/hive/de2667ea-5bc1-4548-a4c4-97e46d6081f8/_tmp_space.db/8e8482c9-a2a4-4e8c-ad0f-2cd6e8fcdb4c
> | NULL |
> | Table Type: | MANAGED_TABLE
>
> | NULL |
> | | NULL
>
> | NULL |
> | # Storage Information | NULL
>
> | NULL |
> | SerDe Library: | org.apache.hadoop.hive.ql.io.orc.OrcSerde
>
> | NULL |
> | InputFormat: |
> org.apache.hadoop.hive.ql.io.orc.OrcInputFormat
> | NULL
> |
> | OutputFormat: |
> org.apache.hadoop.hive.ql.io.orc.OrcOutputFormat
> | NULL
> |
> | Compressed: | No
>
> | NULL |
> | Num Buckets: | -1
>
> | NULL |
> | Bucket Columns: | []
>
> | NULL |
> | Sort Columns: | []
>
> | NULL |
> | Storage Desc Params: | NULL
>
> | NULL |
> | | serialization.format
>
> | 1 |
> +-------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------+-----------------------+--+
> 26 rows selected (0.22 seconds)
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> set hive.server2.enable.doAs;
> +---------------------------------+--+
> | set |
> +---------------------------------+--+
> | hive.server2.enable.doAs=false |
> +---------------------------------+--+
> Permalink Edit Delete
> tsaito Takahiko Saito added a comment - 3 days ago
> hdfs dir of temporary table is owned by hive as expected since
> hive.server2.enable.doAs=false:
> hdfs@hn0-hs21-h:~$ hdfs dfs -ls
> hdfs://hn0-hs21-h.hdinsight.net:8020/tmp/hive/hive/de2667ea-5bc1-4548-a4c4-97e46d6081f8/_tmp_space.db/8e8482c9-a2a4-4e8c-ad0f-2cd6e8fcdb4c
> Found 1 items
> -rwx------ 3 hive hdfs 47777 2016-02-02 23:02
> hdfs://hn0-hs21-h.hdinsight.net:8020/tmp/hive/hive/de2667ea-5bc1-4548-a4c4-97e46d6081f8/_tmp_space.db/8e8482c9-a2a4-4e8c-ad0f-2cd6e8fcdb4c/000000_0
> Not sure if it's related to the JIRA, but one thing I noticed was that dfs
> cmd throws error via beeline:
> 0: jdbc:hive2://zk2-hs21-h.hdinsight.net:2181> dfs -ls
> hdfs://hn0-hs21-h.hdinsight.net:8020/tmp/hive/hive/de2667ea-5bc1-4548-a4c4-97e46d6081f8/_tmp_space.db/8e8482c9-a2a4-4e8c-ad0f-2cd6e8fcdb4c;
> Error: Error while processing statement: Permission denied: user [hrt_qa]
> does not have privilege for [DFS] command (state=,code=1)
> Permalink Edit
> thejas Thejas Nair added a comment - 5 hours ago - edited
> Takahiko Saito
> The above DFS error would be from Ranger of SQL standard authorization. It is
> not related to the test failure.
> But you are right that it looks like a permission issue.
> The issue seen in HIVE-739 also exists in this part of Hive. Hive in MR mode
> launches a new child process to process the small table and create a hash
> table. This child process needs credentials from HDFS. However, in this
> setup, azure fs is the default file system. We should also get delegation
> token from all FS URIs listed under mapreduce.job.hdfs-servers config.
> There are hueristics around when map-join gets used. That is why you don't
> see it unless temp table is used (that uses ORC format and might have stats
> as well, while the original table is probaly text format).
> https://github.com/hortonworks/hive/blob/2.4-maint/ql/src/java/org/apache/hadoop/hive/ql/exec/SecureCmdDoAs.java
> needs change similar to webhcat change in HIVE-739
> Permalink Edit
> sush Sushanth Sowmyan added a comment - 7 minutes ago
> Takahiko Saito, we should file an apache jira for this as well. Would you
> like to do so, so the bug report has attribution to you?
> Permalink Edit Delete
> tsaito Takahiko Saito added a comment - 4 minutes ago
> Sushanth Sowmyan I will file one and update with that JIRA.
> Comment
> People
> Assignee: sush Sushanth Sowmyan
> Assign to me
> Reporter: tsaito Takahiko Saito
> QEAssignee: Takahiko Saito
> Votes: 0
> Watchers: 3 Stop watching this issue
> Dates
> Created: 3 days ago
> Updated: 4 minutes ago
> Who's Looking?
> Agile
> View on Board
> {noformat}
> hivesever2 log shows:
> {noformat}
> 2016-02-02 18:04:43,766 ERROR [HiveServer2-Background-Pool: Thread-517]:
> operation.Operation (SQLOperation.java:run(209)) - 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.MapredLocalTask
> at
> org.apache.hive.service.cli.operation.Operation.toSQLException(Operation.java:315)
> at
> org.apache.hive.service.cli.operation.SQLOperation.runQuery(SQLOperation.java:156)
> at
> org.apache.hive.service.cli.operation.SQLOperation.access$100(SQLOperation.java:71)
> at
> org.apache.hive.service.cli.operation.SQLOperation$1$1.run(SQLOperation.java:206)
> 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:1657)
> at
> org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:218)
> 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)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
