[
https://issues.apache.org/jira/browse/HIVE-12526?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15036326#comment-15036326
]
Hari Sankar Sivarama Subramaniyan commented on HIVE-12526:
----------------------------------------------------------
[~ashutoshc] Thanks for the review. Here is how the lines would look like :
Query :
{code}
explain select i_item_desc ,i_category ,i_class ,i_current_price ,i_item_id
,sum(ws_ext_sales_price) as itemrevenue
,sum(ws_ext_sales_price)*100/sum(sum(ws_ext_sales_price)) over (partition by
i_class) as revenueratio from web_sales ,item ,date_dim where
web_sales.ws_item_sk = item.i_item_sk and item.i_category in ('Jewelry',
'Sports', 'Books') and web_sales.ws_sold_date_sk = date_dim.d_date_sk and
date_dim.d_date between '2001-01-12' and '2001-02-11' group by i_item_id
,i_item_desc ,i_category ,i_class ,i_current_price order by i_category ,i_class
,i_item_id ,i_item_desc ,revenueratio limit 100
{code}
PerfLog output for optimizer :
{code}
2015-12-01T16:31:30,807 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016290242 end=1449016290807 duration=565
from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction
Calcite: Plan generation>
2015-12-01T16:31:30,972 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016290807 end=1449016290972 duration=165
from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction
Calcite: Prejoin ordering transformations>
2015-12-01T16:31:31,041 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016290972 end=1449016291041 duration=69
from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction
Calcite: Join Reordering>
2015-12-01T16:31:31,059 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291042 end=1449016291059 duration=17
from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction
Calcite: Optimizations without stats>
2015-12-01T16:31:31,064 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291059 end=1449016291064 duration=5
from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction
Calcite: Remove projects on top of join operators>
2015-12-01T16:31:31,070 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291064 end=1449016291070 duration=6
from=org.apache.hadoop.hive.ql.parse.CalcitePlanner$CalcitePlannerAction
Calcite: Window fixing rule>
2015-12-01T16:31:31,244 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291244 end=1449016291244 duration=0
from=org.apache.hadoop.hive.ql.optimizer.calcite.translator.HiveOpConverterPostProc
org.apache.hadoop.hive.ql.optimizer.calcite.translator.HiveOpConverterPostProc@7a35614d>
2015-12-01T16:31:31,286 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291245 end=1449016291286 duration=41
from=org.apache.hadoop.hive.ql.optimizer.lineage.Generator
org.apache.hadoop.hive.ql.optimizer.lineage.Generator@59d8da5>
2015-12-01T16:31:31,295 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291287 end=1449016291295 duration=8
from=org.apache.hadoop.hive.ql.optimizer.PointLookupOptimizer
org.apache.hadoop.hive.ql.optimizer.PointLookupOptimizer@149e33f>
2015-12-01T16:31:31,304 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291295 end=1449016291304 duration=9
from=org.apache.hadoop.hive.ql.optimizer.PartitionColumnsSeparator
org.apache.hadoop.hive.ql.optimizer.PartitionColumnsSeparator@276ad430>
2015-12-01T16:31:31,319 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291305 end=1449016291319 duration=14
from=org.apache.hadoop.hive.ql.ppd.PredicateTransitivePropagate
org.apache.hadoop.hive.ql.ppd.PredicateTransitivePropagate@1d85f58b>
2015-12-01T16:31:31,343 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291320 end=1449016291343 duration=23
from=org.apache.hadoop.hive.ql.optimizer.ConstantPropagate
org.apache.hadoop.hive.ql.optimizer.ConstantPropagate@2b22e091>
2015-12-01T16:31:31,348 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291343 end=1449016291348 duration=5
from=org.apache.hadoop.hive.ql.ppd.SyntheticJoinPredicate
org.apache.hadoop.hive.ql.ppd.SyntheticJoinPredicate@700c657a>
2015-12-01T16:31:31,381 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291348 end=1449016291381 duration=33
from=org.apache.hadoop.hive.ql.ppd.PredicatePushDown
org.apache.hadoop.hive.ql.ppd.PredicatePushDown@7d675c59>
2015-12-01T16:31:31,399 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291381 end=1449016291399 duration=18
from=org.apache.hadoop.hive.ql.optimizer.ConstantPropagate
org.apache.hadoop.hive.ql.optimizer.ConstantPropagate@2fac34de>
2015-12-01T16:31:31,407 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291399 end=1449016291407 duration=8
from=org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner
org.apache.hadoop.hive.ql.optimizer.ppr.PartitionPruner@41041c61>
2015-12-01T16:31:31,412 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291407 end=1449016291412 duration=5
from=org.apache.hadoop.hive.ql.optimizer.pcr.PartitionConditionRemover
org.apache.hadoop.hive.ql.optimizer.pcr.PartitionConditionRemover@3a049b2e>
2015-12-01T16:31:31,427 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291412 end=1449016291427 duration=15
from=org.apache.hadoop.hive.ql.optimizer.ConstantPropagate
org.apache.hadoop.hive.ql.optimizer.ConstantPropagate@6fc56177>
2015-12-01T16:31:31,428 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291427 end=1449016291428 duration=1
from=org.apache.hadoop.hive.ql.optimizer.GroupByOptimizer
org.apache.hadoop.hive.ql.optimizer.GroupByOptimizer@691374ac>
2015-12-01T16:31:31,439 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291428 end=1449016291439 duration=11
from=org.apache.hadoop.hive.ql.optimizer.ColumnPruner
org.apache.hadoop.hive.ql.optimizer.ColumnPruner@542e1c68>
2015-12-01T16:31:31,440 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291439 end=1449016291440 duration=1
from=org.apache.hadoop.hive.ql.optimizer.SamplePruner
org.apache.hadoop.hive.ql.optimizer.SamplePruner@7bdaf54f>
2015-12-01T16:31:31,440 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291440 end=1449016291440 duration=0
from=org.apache.hadoop.hive.ql.optimizer.MapJoinProcessor
org.apache.hadoop.hive.ql.optimizer.MapJoinProcessor@1ca778d3>
2015-12-01T16:31:31,441 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291440 end=1449016291441 duration=1
from=org.apache.hadoop.hive.ql.optimizer.BucketingSortingReduceSinkOptimizer
org.apache.hadoop.hive.ql.optimizer.BucketingSortingReduceSinkOptimizer@1f2f70ed>
2015-12-01T16:31:31,441 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291441 end=1449016291441 duration=0
from=org.apache.hadoop.hive.ql.optimizer.unionproc.UnionProcessor
org.apache.hadoop.hive.ql.optimizer.unionproc.UnionProcessor@64c351ea>
2015-12-01T16:31:31,442 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291442 end=1449016291442 duration=0
from=org.apache.hadoop.hive.ql.optimizer.JoinReorder
org.apache.hadoop.hive.ql.optimizer.JoinReorder@53370d54>
2015-12-01T16:31:31,447 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291442 end=1449016291447 duration=5
from=org.apache.hadoop.hive.ql.optimizer.correlation.ReduceSinkDeDuplication
org.apache.hadoop.hive.ql.optimizer.correlation.ReduceSinkDeDuplication@253007b7>
2015-12-01T16:31:31,448 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291447 end=1449016291448 duration=1
from=org.apache.hadoop.hive.ql.optimizer.NonBlockingOpDeDupProc
org.apache.hadoop.hive.ql.optimizer.NonBlockingOpDeDupProc@acfe0cb>
2015-12-01T16:31:31,451 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291448 end=1449016291451 duration=3
from=org.apache.hadoop.hive.ql.optimizer.IdentityProjectRemover
org.apache.hadoop.hive.ql.optimizer.IdentityProjectRemover@148f7c01>
2015-12-01T16:31:31,452 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291451 end=1449016291452 duration=1
from=org.apache.hadoop.hive.ql.optimizer.LimitPushdownOptimizer
org.apache.hadoop.hive.ql.optimizer.LimitPushdownOptimizer@18b64fcc>
2015-12-01T16:31:31,452 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291452 end=1449016291452 duration=0
from=org.apache.hadoop.hive.ql.optimizer.SimpleFetchOptimizer
org.apache.hadoop.hive.ql.optimizer.SimpleFetchOptimizer@6930e6c0>
2015-12-01T16:31:31,542 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=optimizer
start=1449016291453 end=1449016291542 duration=89
from=org.apache.hadoop.hive.ql.parse.TezCompiler Tez compiler>
2015-12-01T16:31:31,586 INFO [b6af6b59-1ea9-4bed-94a8-6586be786cdc main]:
log.PerfLogger (PerfLogger.java:PerfLogEnd(162)) - </PERFLOG method=compile
start=1449016290181 end=1449016291586 duration=1405
from=org.apache.hadoop.hive.ql.Driver>
{code}
> PerfLogger for hive compiler and optimizer
> ------------------------------------------
>
> Key: HIVE-12526
> URL: https://issues.apache.org/jira/browse/HIVE-12526
> Project: Hive
> Issue Type: Bug
> Reporter: Hari Sankar Sivarama Subramaniyan
> Assignee: Hari Sankar Sivarama Subramaniyan
> Attachments: HIVE-12526.1.patch, HIVE-12526.2.patch
>
>
> This jira is intended to use the perflogger to track compilation times and
> optimization times (calcite, tez compiler, physical compiler) etc.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
