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)
