Takahiko Saito created HIVE-13017:
-------------------------------------
Summary: A child process of MR job needs delegation token from
AZURE file system
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
The following query fails:
{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)
