hive-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Antonio Piccolboni (JIRA)" <j...@apache.org>
Subject [jira] [Created] (HIVE-13037) Query with UDF never terminate
Date Wed, 10 Feb 2016 20:52:18 GMT
Antonio Piccolboni created HIVE-13037:
-----------------------------------------

             Summary: Query with UDF never terminate
                 Key: HIVE-13037
                 URL: https://issues.apache.org/jira/browse/HIVE-13037
             Project: Hive
          Issue Type: Bug
          Components: HiveServer2
    Affects Versions: 1.0.0
            Reporter: Antonio Piccolboni
            Assignee: Vaibhav Gumashta


I am writing a client for HS2 that uses the JDBC interface. I can execute a simple select
query. When I add a UDF to the query, the  client hangs. I looked at the logs (larger excerpt
below) and there is this bit that looks suspect, and repeats ad infinitum

{code}
2016-02-10 20:26:49,571 INFO  [hiveServer2.async.multi_dest.batch_hiveServer2.async.multi_dest.batch.db_destWriter]:
queue.AuditFileSpool (AuditFileSpool.java:runDoAs(780)) - Destination is down. sleeping for
30000 milli seconds. indexQueue=0, queueName=hiveServer2.async.multi_dest.batch, consumer=hiveServer2.async.multi_dest.batch.db
{code}

No tez dag is ever submitted or executed, per log and web UI. The only special thing about
this UDF may be that it accesses a file that has been added with ADD FILE from hdfs. 

Log from query submission to infinite loop first few iterations:

{code}
2016-02-10 20:24:32,695 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.ParseDriver (ParseDriver.java:parse(185))
- Parsing command: SELECT count(*) FROM (SELECT `mpg`, `cyl`, 
`disp`, `hp`, `drat`, `wt`, `qsec`, `vs`, `am`, `gear`, `carb`, rudfdouble('/tmp/8d4a5fc1-a5d1-4048-81dc-e1e3b86b3074_resources/squareudf',
`carb`) AS `sq`
FROM `mtcars`) AS `master`
2016-02-10 20:24:32,698 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.ParseDriver (ParseDriver.java:parse(209))
- Parse Completed
2016-02-10 20:24:32,699 INFO  [HiveServer2-Handler-Pool: Thread-4907]: log.PerfLogger (PerfLogger.java:PerfLogEnd(148))
- </PERFLOG method=parse start=1455135872695 end=145513587269
9 duration=4 from=org.apache.hadoop.hive.ql.Driver>
2016-02-10 20:24:32,704 INFO  [HiveServer2-Handler-Pool: Thread-4907]: log.PerfLogger (PerfLogger.java:PerfLogBegin(121))
- <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hi
ve.ql.Driver>
2016-02-10 20:24:32,704 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:analyzeInternal(10105)) - Starting Semantic Analysis
2016-02-10 20:24:32,704 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:genResolvedParseTree(10052)) - Completed phase 1 of Semantic Analy
sis
2016-02-10 20:24:32,705 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:getMetaData(1534)) - Get metadata for source tables
2016-02-10 20:24:32,705 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:getMetaData(1686)) - Get metadata for subqueries
2016-02-10 20:24:32,705 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:getMetaData(1534)) - Get metadata for source tables
2016-02-10 20:24:32,706 INFO  [HiveServer2-Handler-Pool: Thread-4907]: metastore.ObjectStore
(ObjectStore.java:initialize(290)) - ObjectStore, initialize called
2016-02-10 20:24:32,708 WARN  [HiveServer2-Handler-Pool: Thread-4907]: metastore.MetaStoreDirectSql
(MetaStoreDirectSql.java:determineDbType(160)) - DB Product name[MySQL] obtained,
 but not used to determine db type. Falling back to using SQL to determine which db we're
using
2016-02-10 20:24:32,713 INFO  [HiveServer2-Handler-Pool: Thread-4907]: metastore.MetaStoreDirectSql
(MetaStoreDirectSql.java:<init>(140)) - Using direct SQL, underlying DB is MYSQL
2016-02-10 20:24:32,713 INFO  [HiveServer2-Handler-Pool: Thread-4907]: metastore.ObjectStore
(ObjectStore.java:setConf(273)) - Initialized ObjectStore
2016-02-10 20:24:32,714 INFO  [HiveServer2-Handler-Pool: Thread-4907]: metastore.HiveMetaStore
(HiveMetaStore.java:logInfo(747)) - 213: get_table : db=default tbl=mtcars
2016-02-10 20:24:32,714 INFO  [HiveServer2-Handler-Pool: Thread-4907]: HiveMetaStore.audit
(HiveMetaStore.java:logAuditEvent(372)) - ugi=hive   ip=unknown-ip-addr      cmd=get_table
 : db=default tbl=mtcars   
2016-02-10 20:24:32,753 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:getMetaData(1686)) - Get metadata for subqueries
2016-02-10 20:24:32,753 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:getMetaData(1710)) - Get metadata for destination tables
2016-02-10 20:24:32,753 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:getMetaData(1710)) - Get metadata for destination tables
2016-02-10 20:24:32,772 INFO  [HiveServer2-Handler-Pool: Thread-4907]: ql.Context (Context.java:getMRScratchDir(330))
- New scratch dir is hdfs://sandbox.hortonworks.com:8020/tmp/hi
ve/hive/8d4a5fc1-a5d1-4048-81dc-e1e3b86b3074/hive_2016-02-10_20-24-32_695_972448943093277787-40
2016-02-10 20:24:32,772 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.CalcitePlanner
(SemanticAnalyzer.java:genResolvedParseTree(10056)) - Completed getting MetaData in Seman
tic Analysis
2016-02-10 20:24:32,772 INFO  [HiveServer2-Handler-Pool: Thread-4907]: parse.BaseSemanticAnalyzer
(CalcitePlanner.java:canCBOHandleAst(392)) - Not invoking CBO because the statement
 has too few joins
2016-02-10 20:24:33,382 INFO  [HiveServer2-Handler-Pool: Thread-4907]: log.PerfLogger (PerfLogger.java:PerfLogEnd(148))
- </PERFLOG method=compile start=1455135872694 end=1455135873382 duration=688 from=org.apache.hadoop.hive.ql.Driver>
2016-02-10 20:24:49,568 INFO  [hiveServer2.async.multi_dest.batch_hiveServer2.async.multi_dest.batch.db_destWriter]:
queue.AuditFileSpool (AuditFileSpool.java:runDoAs(780)) - Destination is down. sleeping for
30000 milli seconds. indexQueue=0, queueName=hiveServer2.async.multi_dest.batch, consumer=hiveServer2.async.multi_dest.batch.db
2016-02-10 20:24:52,083 INFO  [org.apache.ranger.audit.queue.AuditBatchQueue1]: provider.BaseAuditHandler
(BaseAuditHandler.java:logStatus(301)) - Audit Status Log: name=hiveServer2.async.multi_dest.batch,
finalDestination=hiveServer2.async.multi_dest.batch.hdfs, interval=01:00.009 minutes, events=14,
succcessCount=5, totalEvents=420, totalSuccessCount=111, totalStashedCount=184
2016-02-10 20:25:03,352 INFO  [org.apache.ranger.audit.queue.AuditBatchQueue0]: provider.BaseAuditHandler
(BaseAuditHandler.java:logStatus(301)) - Audit Status Log: name=hiveServer2.async.multi_dest.batch,
finalDestination=hiveServer2.async.multi_dest.batch.db, interval=01:02.999 minutes, events=5,
succcessCount=2, totalEvents=717, totalSuccessCount=295
2016-02-10 20:25:31,635 INFO  [HiveServer2-Handler-Pool: Thread-5400]: thrift.ThriftCLIService
(ThriftCLIService.java:OpenSession(294)) - Client protocol version: HIVE_CLI_SERVICE_PROTOCOL_V8
2016-02-10 20:25:31,653 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created local directory: /tmp/47f78843-0f14-4db5-ad7c-318b37ac44c9_resources
2016-02-10 20:25:31,662 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created HDFS directory: /tmp/hive/hive/47f78843-0f14-4db5-ad7c-318b37ac44c9
2016-02-10 20:25:31,665 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created local directory: /tmp/hive/47f78843-0f14-4db5-ad7c-318b37ac44c9
2016-02-10 20:25:31,672 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created HDFS directory: /tmp/hive/hive/47f78843-0f14-4db5-ad7c-318b37ac44c9/_tmp_space.db
2016-02-10 20:25:31,675 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.HiveSessionImpl
(HiveSessionImpl.java:setOperationLogSessionDir(236)) - Operation log session directory is
created: /home/hive/${system:java.io.tmpdir}/${system:user.name}/operation_logs/47f78843-0f14-4db5-ad7c-318b37ac44c9
2016-02-10 20:25:49,569 INFO  [hiveServer2.async.multi_dest.batch_hiveServer2.async.multi_dest.batch.db_destWriter]:
queue.AuditFileSpool (AuditFileSpool.java:runDoAs(780)) - Destination is down. sleeping for
30000 milli seconds. indexQueue=0, queueName=hiveServer2.async.multi_dest.batch, consumer=hiveServer2.async.multi_dest.batch.db
2016-02-10 20:26:30,890 INFO  [HiveServer2-Handler-Pool: Thread-5400]: thrift.ThriftCLIService
(ThriftCLIService.java:OpenSession(294)) - Client protocol version: HIVE_CLI_SERVICE_PROTOCOL_V8
2016-02-10 20:26:30,902 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created local directory: /tmp/2ca839b8-f6e5-465d-9ae7-3cbe5418be64_resources
2016-02-10 20:26:30,910 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created HDFS directory: /tmp/hive/hive/2ca839b8-f6e5-465d-9ae7-3cbe5418be64
2016-02-10 20:26:30,914 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created local directory: /tmp/hive/2ca839b8-f6e5-465d-9ae7-3cbe5418be64
2016-02-10 20:26:30,922 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created HDFS directory: /tmp/hive/hive/2ca839b8-f6e5-465d-9ae7-3cbe5418be64/_tmp_space.db
2016-02-10 20:26:30,926 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.HiveSessionImpl
(HiveSessionImpl.java:setOperationLogSessionDir(236)) - Operation log session directory is
created: /home/hive/${system:java.io.tmpdir}/${system:user.name}/operation_logs/2ca839b8-f6e5-465d-9ae7-3cbe5418be64
2016-02-10 20:26:49,571 INFO  [hiveServer2.async.multi_dest.batch_hiveServer2.async.multi_dest.batch.db_destWriter]:
queue.AuditFileSpool (AuditFileSpool.java:runDoAs(780)) - Destination is down. sleeping for
30000 milli seconds. indexQueue=0, queueName=hiveServer2.async.multi_dest.batch, consumer=hiveServer2.async.multi_dest.batch.db
2016-02-10 20:27:31,748 INFO  [HiveServer2-Handler-Pool: Thread-5400]: thrift.ThriftCLIService
(ThriftCLIService.java:OpenSession(294)) - Client protocol version: HIVE_CLI_SERVICE_PROTOCOL_V8
2016-02-10 20:27:31,763 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created local directory: /tmp/701b1cef-63c4-4c13-a275-fe28469eccc8_resources
2016-02-10 20:27:31,771 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created HDFS directory: /tmp/hive/hive/701b1cef-63c4-4c13-a275-fe28469eccc8
2016-02-10 20:27:31,776 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created local directory: /tmp/hive/701b1cef-63c4-4c13-a275-fe28469eccc8
2016-02-10 20:27:31,783 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.SessionState
(SessionState.java:createPath(641)) - Created HDFS directory: /tmp/hive/hive/701b1cef-63c4-4c13-a275-fe28469eccc8/_tmp_space.db
2016-02-10 20:27:31,787 INFO  [HiveServer2-Handler-Pool: Thread-5400]: session.HiveSessionImpl
(HiveSessionImpl.java:setOperationLogSessionDir(236)) - Operation log session directory is
created: /home/hive/${system:java.io.tmpdir}/${system:user.name}/operation_logs/701b1cef-63c4-4c13-a275-fe28469eccc8
2016-02-10 20:27:49,572 INFO  [hiveServer2.async.multi_dest.batch_hiveServer2.async.multi_dest.batch.db_destWriter]:
queue.AuditFileSpool (AuditFileSpool.java:runDoAs(780)) - Destination is down. sleeping for
30000 milli seconds. indexQueue=0, queueName=hiveServer2.async.multi_dest.batch, consumer=hiveServer2.async.multi_dest.batch.db
2016-02-10 20:28:31,397 INFO  [HiveServer2-Handler-Pool: Thread-5400]: thrift.ThriftCLIService
(ThriftCLIService.java:OpenSession(294)) - Client protocol version: HIVE_CLI_SERVICE_PROTOCOL_V8
{code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message