[
https://issues.apache.org/jira/browse/DERBY-4297?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Bryan Pendleton updated DERBY-4297:
-----------------------------------
Assignee: Bryan Pendleton
I think that this may be due to the way that 'compileTime' is computed
in GenericStatement.prepMinion(). During the processing of the statement,
GenericStatement computes the overall time that was taken, and breaks
it down into various phases: parse time, bind time, optimize time, generate
time,
and overall compileTime. It does this by calling System.currentTimeMillis() at
various points, and recording the value.
However, I think there is a hole in the current algorithm in which, if the
System.currentTimeMillis clock "ticks" *after* the line
generateTime = getCurrentTimeMillis(lcc); (line 471)
and *before* the line
preparedStmt.setCompileTimeMillis(...) (line 521)
then we can have a result where compileTime !=
(parseTime+bindTime+optimizeTime+generateTime),
which is the invariant being tested by the test.
I think that we may be able to fix this with the following change (not yet
tested):
Index: GenericStatement.java
===================================================================
--- GenericStatement.java (revision 884222)
+++ GenericStatement.java (working copy)
@@ -521,7 +521,7 @@
bindTime - parseTime, //bind
time
optimizeTime - bindTime,
//optimize time
generateTime - optimizeTime,
//generate time
- getElapsedTimeMillis(beginTime),
+ generateTime -
beginTime,//compile time
beginTimestamp,
endTimestamp);
}
I'm not sure how important or useful these times are, nowadays; modern
processors are so fast, and System.currentTimeMillis is so slow, then
in general the times are always (0,0,0,0).
But I'll experiment with this change, and if it doesn't seem to do any harm,
we can see if it makes this test more reliable.
> 'compilation time did not compute (0,0,0,0) expected:<16> but was:<0>' in
> testGroupBySortProps(....tests.lang.XplainStatisticsTest)
> -----------------------------------------------------------------------------------------------------------------------------------
>
> Key: DERBY-4297
> URL: https://issues.apache.org/jira/browse/DERBY-4297
> Project: Derby
> Issue Type: Bug
> Components: SQL, Test
> Affects Versions: 10.6.0.0
> Environment: OS:
> Microsoft Windows XP Professional - 5.1.2600 Service Pack 3 Build 2600
> CYGWIN_NT-5.1 1.5.25(0.156/4/2) 2008-06-12 19:34 Cygwin
> JVM:
> Sun Microsystems Inc.
> java version "1.5.0_16"
> Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_16-b02)
> Java HotSpot(TM) Client VM (build 1.5.0_16-b02, mixed mode, sharing)
> Reporter: Ole Solberg
> Assignee: Bryan Pendleton
> Priority: Minor
>
> Seen in
> http://dbtg.thresher.com/derby/test/trunk15/jvm1.5/testing/testlog/CYGWIN_NT-5.1_i686-unknown/790694-org.apache.derbyTesting.functionTests.suites.All_diff.txt
> There was 1 failure:
> 1)
> testGroupBySortProps(org.apache.derbyTesting.functionTests.tests.lang.XplainStatisticsTest)junit.framework.AssertionFailedError:
> compilation time did not compute (0,0,0,0) expected:<16> but was:<0>
> at
> org.apache.derbyTesting.functionTests.tests.lang.XplainStatisticsTest.verifySensibleStatementTimings(XplainStatisticsTest.java:707)
> at
> org.apache.derbyTesting.functionTests.tests.lang.XplainStatisticsTest.testGroupBySortProps(XplainStatisticsTest.java:1011)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at
> org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:109)
> at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
> at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
> at junit.extensions.TestSetup.run(TestSetup.java:23)
> at
> org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
