Kathey Marsden wrote:
Army wrote:
If you're in a situation where you have to use printlns, you may want
to start by printing out the contents of the bestJoinOrder array in
OptimizerImpl in two places: 1) at the end of rememberBestCost(), and
2) at the end of modifyAccessPaths(). The former tells you every
time the OptimizerImpl thinks it has found a new "best join order"
thus far in processing, the latter tells you what the OptimizerImpl's
_final_ choice of "best join order" was. If you print out the cost
of the join orders (bestCost) as well, and then compare the results
from a "fail" plan and a "pass" plan, that might give you an
indication of where to start. But as I said, there's no silver
bullet in tracking that kind of thing down...
Well I finally got the printlns with the failing and passing runs. It
seemed much less likely to happen once I put them in, but eventually I
got a hit, but I don't think I am understanding what I am seeing. I
expected to see large costs with the failing run. But I think I
messed up and printed the current cost instead of the best cost, so I
will try to print that out too and see what happens.
Kathey
Oops it would help to attach the files.
select count(*) from (select * from t1 union select * from t3) x1 (c, d),
(select * from t2 union select * from t4) x2 (e, f) where x1.c = x2.e
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:14137.132000000001 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:5.3663282674826086E7 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.90255744984E8 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.94063142716E8 bestJoinOrder:{0,1}
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:12643.436 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3392499.9599999995 bestJoinOrder:{0}
After rememberBestCost(), currentCost:4.9860544042893946E7 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3392499.9599999995 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.90273744164E8 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.936789570400001E8 bestJoinOrder:{1,0}
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:14137.132000000001 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:5.3663282674826086E7 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.90255744984E8 bestJoinOrder:{0}
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:12643.436 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,0}
used 38533 ms After rememberBestCost(), currentCost:2.5557 bestJoinOrder:{0}
After rememberBestCost(), currentCost:2.5557 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:168.99599999999998 bestJoinOrder:{0,1}
After rememberBestCost(), currentCost:36.5721 bestJoinOrder:{1,0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,0}
After rememberBestCost(), currentCost:145.52056875 bestJoinOrder:{0,1}
After rememberBestCost(), currentCost:10.9367 bestJoinOrder:{1,0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.34607875 bestJoinOrder:{0,1,2}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.160915360835899 bestJoinOrder:{0,2,1}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.113251999999999 bestJoinOrder:{1,0,2}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:5.749100576 bestJoinOrder:{1,2,0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,2,0}
After rememberBestCost(), currentCost:20.039500000000004 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
Time: 50.916
OK (1 test)
select count(*) from (select * from t1 union select * from t3) x1 (c, d),
(select * from t2 union select * from t4) x2 (e, f) where x1.c = x2.e
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:14137.132000000001 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:5.3663282674826086E7 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.90255744984E8 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3.136778744561347E12 bestJoinOrder:{0,1}
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:12643.436 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3392499.9599999995 bestJoinOrder:{0}
After rememberBestCost(), currentCost:4.9860544042893946E7 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3392499.9599999995 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.90273744164E8 bestJoinOrder:{0}
After rememberBestCost(), currentCost:2.6001863922422188E12 bestJoinOrder:{1,0}
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:14137.132000000001 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:5.3663282674826086E7 bestJoinOrder:{0}
After rememberBestCost(), currentCost:3793191.1199999996 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.90255744984E8 bestJoinOrder:{0}
After rememberBestCost(), currentCost:69.47999999999999 bestJoinOrder:{0}
After rememberBestCost(), currentCost:12643.436 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,0}
FAfter rememberBestCost(), currentCost:2.5557 bestJoinOrder:{0}
After rememberBestCost(), currentCost:2.5557 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:168.99599999999998 bestJoinOrder:{0,1}
After rememberBestCost(), currentCost:36.5721 bestJoinOrder:{1,0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,0}
After rememberBestCost(), currentCost:145.52056875 bestJoinOrder:{0,1}
After rememberBestCost(), currentCost:10.9367 bestJoinOrder:{1,0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.34607875 bestJoinOrder:{0,1,2}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.160915360835899 bestJoinOrder:{0,2,1}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:6.113251999999999 bestJoinOrder:{1,0,2}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:5.749100576 bestJoinOrder:{1,2,0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After rememberBestCost(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{1,2,0}
After rememberBestCost(), currentCost:20.039500000000004 bestJoinOrder:{0}
After modifyAccesPaths(), currentCost:0.0 bestJoinOrder:{0}
Time: 63.759
There was 1 failure:
1)
test_predicatePushdown(org.apache.derbyTesting.functionTests.tests.lang.PredicatePushdownTest)junit.framework.AssertionFailedError:
Expected Table Scan ResultSet for T3
at
org.apache.derbyTesting.functionTests.tests.lang.PredicatePushdownTest.test_predicatePushdown(PredicatePushdownTest.java:1374)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:45)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:104)
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)
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)
FAILURES!!!
Tests run: 1, Failures: 1, Errors: 0
