[
https://issues.apache.org/jira/browse/HIVE-8785?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Thejas M Nair updated HIVE-8785:
--------------------------------
Fix Version/s: 0.14.0
> 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
> Fix For: 0.14.0
>
> Attachments: HIVE-8785.1.patch
>
>
> 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)
