You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hive.apache.org by "Lefty Leverenz (JIRA)" <ji...@apache.org> on 2014/12/14 12:09:13 UTC

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

    [ https://issues.apache.org/jira/browse/HIVE-8785?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14245887#comment-14245887 ] 

Lefty Leverenz commented on HIVE-8785:
--------------------------------------

Doc done:  *hive.server2.logging.operation.enabled* and *hive.server2.logging.operation.verbose* are documented in the wiki.

* [hive.server2.logging.operation.enabled | https://cwiki.apache.org/confluence/display/Hive/Configuration+Properties#ConfigurationProperties-hive.server2.logging.operation.enabled]
* [hive.server2.logging.operation.verbose | https://cwiki.apache.org/confluence/display/Hive/Configuration+Properties#ConfigurationProperties-hive.server2.logging.operation.verbose]

Some guidance about how to use them could be added to one of the HiveServer2 docs (probably Setting Up HS2), with links to & from the logging section in Getting Started.  If that is not needed, the TODOC14 label can be removed.

* [Setting Up HiveServer2 | https://cwiki.apache.org/confluence/display/Hive/Setting+Up+HiveServer2]
* [HiveServer2 Clients | https://cwiki.apache.org/confluence/display/Hive/HiveServer2+Clients]
* [Getting Started -- Error Logs | https://cwiki.apache.org/confluence/display/Hive/GettingStarted#GettingStarted-ErrorLogs]

> 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
>              Labels: TODOC14
>             Fix For: 0.14.0
>
>         Attachments: HIVE-8785.1.patch, HIVE-8785.2.patch, HIVE-8785.3.patch, HIVE-8785.4.patch, HIVE-8785.4.patch, HIVE-8785.5.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)