Mailing-List: contact issues-help@hive.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@hive.apache.org
Date: Sun, 8 Nov 2015 18:24:10 +0000 (UTC)
From: "Hive QA (JIRA)" <jira@apache.org>
To: issues@hive.apache.org
Message-ID: <JIRA.12909469.1446349717000.10715.1447007050941@Atlassian.JIRA>
In-Reply-To: <JIRA.12909469.1446349717000@Atlassian.JIRA>
References: <JIRA.12909469.1446349717000@Atlassian.JIRA>
 <JIRA.12909469.1446349717588@arcas>
Subject: [jira] [Commented] (HIVE-12312) Excessive logging in PPD code
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit


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

Hive QA commented on HIVE-12312:
--------------------------------


Here are the results of testing the latest attachment:
https://issues.apache.org/jira/secure/attachment/12771236/HIVE-12312.2.patch

{color:red}ERROR:{color} -1 due to no test(s) being added or modified.

{color:red}ERROR:{color} -1 due to 3 failed/errored test(s), 9777 tests executed
*Failed tests:*
{noformat}
org.apache.hadoop.hive.cli.TestNegativeCliDriver.testNegativeCliDriver_authorization_uri_import
org.apache.hadoop.hive.hwi.TestHWISessionManager.testHiveDriver
org.apache.hive.jdbc.TestSSL.testSSLVersion
{noformat}

Test results: http://ec2-174-129-184-35.compute-1.amazonaws.com/jenkins/job/PreCommit-HIVE-TRUNK-Build/5965/testReport
Console output: http://ec2-174-129-184-35.compute-1.amazonaws.com/jenkins/job/PreCommit-HIVE-TRUNK-Build/5965/console
Test logs: http://ec2-174-129-184-35.compute-1.amazonaws.com/logs/PreCommit-HIVE-TRUNK-Build-5965/

Messages:
{noformat}
Executing org.apache.hive.ptest.execution.TestCheckPhase
Executing org.apache.hive.ptest.execution.PrepPhase
Executing org.apache.hive.ptest.execution.ExecutionPhase
Executing org.apache.hive.ptest.execution.ReportingPhase
Tests exited with: TestsFailedException: 3 tests failed
{noformat}

This message is automatically generated.

ATTACHMENT ID: 12771236 - PreCommit-HIVE-TRUNK-Build

> Excessive logging in PPD code
> -----------------------------
>
>                 Key: HIVE-12312
>                 URL: https://issues.apache.org/jira/browse/HIVE-12312
>             Project: Hive
>          Issue Type: Bug
>          Components: Hive
>    Affects Versions: 1.2.1
>            Reporter: Carter Shanklin
>            Priority: Minor
>         Attachments: HIVE-12312.1.patch, HIVE-12312.2.patch
>
>
> One of my very complex queries takes about 14 minutes to compile with PPD on. Profiling it I saw a lot of time spent in this stack which is called many many thousands of times.
> {code}
> java.lang.Throwable.getStackTraceElement(-2)
> java.lang.Throwable.getOurStackTrace(827)
> java.lang.Throwable.getStackTrace(816)
> sun.reflect.GeneratedMethodAccessor5.invoke(-1)
> sun.reflect.DelegatingMethodAccessorImpl.invoke(43)
> java.lang.reflect.Method.invoke(497)
> org.apache.log4j.spi.LocationInfo.<init>(139)
> org.apache.log4j.spi.LoggingEvent.getLocationInformation(253)
> org.apache.log4j.helpers.PatternParser$LocationPatternConverter.convert(500)
> org.apache.log4j.helpers.PatternConverter.format(65)
> org.apache.log4j.PatternLayout.format(506)
> org.apache.log4j.WriterAppender.subAppend(310)
> org.apache.log4j.DailyRollingFileAppender.subAppend(369)
> org.apache.log4j.WriterAppender.append(162)
> org.apache.log4j.AppenderSkeleton.doAppend(251)
> org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(66)
> org.apache.log4j.Category.callAppenders(206)
> org.apache.log4j.Category.forcedLog(391)
> org.apache.log4j.Category.log(856)
> org.apache.commons.logging.impl.Log4JLogger.info(176)
> org.apache.hadoop.hive.ql.ppd.OpProcFactory$DefaultPPD.logExpr(707)
> org.apache.hadoop.hive.ql.ppd.OpProcFactory$DefaultPPD.mergeWithChildrenPred(752)
> org.apache.hadoop.hive.ql.ppd.OpProcFactory$FilterPPD.process(437)
> {code}
> logExpr is set to log at INFO level, but I think DEBUG is more appropriate. When I set log level to debug I see > 20% speedup in compile time:
> Before:
> {code}
> real    14m47.972s
> user    15m25.609s
> sys    0m20.282s
> {code}
> After:
> {code}
> real    11m30.946s
> user    12m10.870s
> sys    0m7.320s
> {code}
> It looks like there's a lot of stuff in the PPD code that could be optimized, when I turn PPD off the query compiles in 2m 30s. But this seems like an easy and low risk win.


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