You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hive.apache.org by "Thejas M Nair (JIRA)" <ji...@apache.org> on 2014/11/07 23:06:34 UTC

[jira] [Created] (HIVE-8785) HiveServer2 LogDivertAppender should be more selective for beeline getLogs

Thejas M Nair created HIVE-8785:
-----------------------------------

             Summary: HiveServer2 LogDivertAppender should be more selective for beeline getLogs
                 Key: HIVE-8785
                 URL: https://issues.apache.org/jira/browse/HIVE-8785
             Project: Hive
          Issue Type: Bug
            Reporter: Gopal V
            Assignee: Thejas M Nair


A simple query run via beeline JDBC like {{explain select count(1) from testing.foo;}} produces 50 lines of output which looks like 

{code}
0: jdbc:hive2://localhost:10002> explain select count(1) from testing.foo;
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=compile from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=parse from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO parse.ParseDriver: Parsing command: explain select count(1) from testing.foo
14/11/06 00:35:59 INFO parse.ParseDriver: Parse Completed
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=parse start=1415262959379 end=1415262959380 duration=1 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Starting Semantic Analysis
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Completed phase 1 of Semantic Analysis
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Get metadata for source tables
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Get metadata for subqueries
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Get metadata for destination tables
14/11/06 00:35:59 INFO ql.Context: New scratch dir is hdfs://cn041-10.l42scl.hortonworks.com:8020/tmp/hive/gopal/6b3980f6-3238-4e91-ae53-cb3f54092dab/hive_2014-11-06_00-35-59_379_317426424610374080-1
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Completed getting MetaData in Semantic Analysis
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Set stats collection dir : hdfs://cn041-10.l42scl.hortonworks.com:8020/tmp/hive/gopal/6b3980f6-3238-4e91-ae53-cb3f54092dab/hive_2014-11-06_00-35-59_379_317426424610374080-1/-ext-10002
14/11/06 00:35:59 INFO ppd.OpProcFactory: Processing for FS(16)
14/11/06 00:35:59 INFO ppd.OpProcFactory: Processing for SEL(15)
14/11/06 00:35:59 INFO ppd.OpProcFactory: Processing for GBY(14)
14/11/06 00:35:59 INFO ppd.OpProcFactory: Processing for RS(13)
14/11/06 00:35:59 INFO ppd.OpProcFactory: Processing for GBY(12)
14/11/06 00:35:59 INFO ppd.OpProcFactory: Processing for SEL(11)
14/11/06 00:35:59 INFO ppd.OpProcFactory: Processing for TS(10)
14/11/06 00:35:59 INFO optimizer.ColumnPrunerProcFactory: RS 13 oldColExprMap: {VALUE._col0=Column[_col0]}
14/11/06 00:35:59 INFO optimizer.ColumnPrunerProcFactory: RS 13 newColExprMap: {VALUE._col0=Column[_col0]}
14/11/06 00:35:59 INFO parse.SemanticAnalyzer: Completed plan generation
14/11/06 00:35:59 INFO ql.Driver: Semantic Analysis Completed
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=semanticAnalyze start=1415262959381 end=1415262959401 duration=20 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO ql.Driver: Returning Hive schema: Schema(fieldSchemas:[FieldSchema(name:Explain, type:string, comment:null)], properties:null)
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=compile start=1415262959378 end=1415262959402 duration=24 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=Driver.run from=org.apache.hadoop.hive.ql.Driver>
+----------------------------+--+
|          Explain           |
+----------------------------+--+
| STAGE DEPENDENCIES:        |
|   Stage-0 is a root stage  |
|                            |
| STAGE PLANS:               |
|   Stage: Stage-0           |
|     Fetch Operator         |
|       limit: 1             |
|       Processor Tree:      |
|         ListSink           |
|                            |
+----------------------------+--+
10 rows selected (0.1 seconds)
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=TimeToSubmit from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO ql.Driver: Concurrency mode is disabled, not creating a lock manager
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=Driver.execute from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO ql.Driver: Starting command: explain select count(1) from testing.foo
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=TimeToSubmit start=1415262959403 end=1415262959405 duration=2 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=runTasks from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=task.EXPLAIN.Stage-1 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO ql.Driver: Starting task [Stage-1:EXPLAIN] in serial mode
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=runTasks start=1415262959405 end=1415262959408 duration=3 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=Driver.execute start=1415262959404 end=1415262959408 duration=4 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO ql.Driver: OK
14/11/06 00:35:59 INFO log.PerfLogger: <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=releaseLocks start=1415262959408 end=1415262959409 duration=1 from=org.apache.hadoop.hive.ql.Driver>
14/11/06 00:35:59 INFO log.PerfLogger: </PERFLOG method=Driver.run start=1415262959403 end=1415262959409 duration=6 from=org.apache.hadoop.hive.ql.Driver>
{code}

A more complex query like Query27 produces 800+ lines of unnecessary logging.

This is unreadable and in-fact slows down the beeline JDBC client.



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