You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "Ole Solberg (JIRA)" <ji...@apache.org> on 2008/02/28 21:07:51 UTC
[jira] Created: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
----------------------------------------------------------------------------
Key: DERBY-3479
URL: https://issues.apache.org/jira/browse/DERBY-3479
Project: Derby
Issue Type: Bug
Components: Regression Test Failure
Affects Versions: 10.4.0.0
Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
Reporter: Ole Solberg
Seen in tinderbox since r631930.
See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
*** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
9285 del
< Rows seen from the left = 20
9285a9285
> Rows seen from the left = 10
9297 del
< Rows seen from the right = 20
9297a9297
> Rows seen from the right = 10
9299 del
< Rows returned = 20
9299a9299
> Rows returned = 10
.
.
.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Resolved: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "A B (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
A B resolved DERBY-3479.
------------------------
Resolution: Fixed
Fix Version/s: 10.4.0.0
Assignee: A B
> Compressing the tables seems to have fixed the problem. I've run the test more
> than 20 times without seeing the failure.
Great, thanks for testing it out, Knut Anders. Based on that feedback, along with the fact that a) the test has not failed in the past several tinderbox runs, and b) it appears the extra page after compression is "odd" but explainable, I'm marking this as resolved. Please feel to re-open if the diff shows up again...
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
> Assignee: A B
> Fix For: 10.4.0.0
>
> Attachments: d3479_1.diff
>
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Issue Comment Edited: (DERBY-3479) Changed/unexpected query
plan when running test 'lang/predicatePushdown.sql'
Posted by "A B (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575939#action_12575939 ]
army edited comment on DERBY-3479 at 3/6/08 2:53 PM:
----------------------------------------------------
> Compressing the tables seems to have fixed the problem. I've run the test more
> than 20 times without seeing the failure.
Great, thanks for testing it out, Knut Anders. Based on that feedback, along with the fact that a) the test has not failed in the past several tinderbox runs, and b) it appears the extra page after compression is "odd" but explainable[1], I'm marking this as resolved. Please feel to re-open if the diff shows up again...
[1] http://article.gmane.org/gmane.comp.apache.db.derby.devel/56253
was (Author: army):
> Compressing the tables seems to have fixed the problem. I've run the test more
> than 20 times without seeing the failure.
Great, thanks for testing it out, Knut Anders. Based on that feedback, along with the fact that a) the test has not failed in the past several tinderbox runs, and b) it appears the extra page after compression is "odd" but explainable, I'm marking this as resolved. Please feel to re-open if the diff shows up again...
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
> Assignee: A B
> Fix For: 10.4.0.0
>
> Attachments: d3479_1.diff
>
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "A B (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575441#action_12575441 ]
A B commented on DERBY-3479:
----------------------------
> I noticed that other tests that depend on stable query plans (wisconsin and StalePlansTest)
> set derby.storage.checkpointInterval=100000.
This is an interesting observation. When I read it I assumed that this number was greater than the default and that by setting it we were avoiding checkpoints. But it turns out that the opposite is true: the default checkpoint interval is 10*1024*1024, while 100000 is the *minimum* checkpoint interval allowed (see raw/LogToFile.java). With the default interval we will not do any checkpoints during the running of predicatePushdown.sql; but with the minimum interval of 100000, we do THREE checkpoints (at least on my machine).
So I wonder if the checkpoint does something which updates the row counts and/or statistics for the tables, thus affecting the optimizer's decisions? I have no idea what the answer to that might be...
> Perhaps changing the concurrency/timing in the buffer manager somehow changes when
> the row count is flushed
While scanning LogToFile.java for the default checkpoint interval, I noticed the following:
/////////////////////////////////////////////////////////////
// setup checkpoint daemon and cache cleaner
/////////////////////////////////////////////////////////////
checkpointDaemon = rawStoreFactory.getDaemon();
if (checkpointDaemon != null)
{
myClientNumber =
checkpointDaemon.subscribe(this, true /*onDemandOnly */);
// use the same daemon for the cache cleaner
dataFactory.setupCacheCleaner(checkpointDaemon);
}
Note how the *same* daemon service is used for checkpointing and for cleaning the cache. The call to "setupCacheCleaner" ultimately ends up at CacheManager.java, which was modified by DERBY-2911. So I wonder if this daemon "sharing" could explain a) why a different cache manager has an effect on predicatePushdown.sql, and/or b) why changing the checkpoint interval seems to alleviate the effect?
Not sure if that's useful info or not, as I'm completely out of my knowledge base here. But I thought I'd mention it.
In the meantime, do you think it would be worth it set checkpointInterval to 100000 to see if that gets predicatePushdown passing in the tinderbox again?
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "A B (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575050#action_12575050 ]
A B commented on DERBY-3479:
----------------------------
> The predicatePushdown test is known to be unstable due to varying query plans
True, though I don't think this particular difference has ever shown up before? Usually the diffs are rather large, but this one is relatively small--the join order of two tables for a single query has been switched, and that's it.
> Rewriting the unstable parts of the test in JUnit and only check the relevant parts
> of the query plan sounds like a reasonable approach to me.
I agree. Probably not a trivial task, but one worth doing if anyone is so inclined.
The question of *why* we intermittently get different plans even though the "noTimeout" property is set to true remains a mystery. And in particular, how does the buffer manager come into play for optimizer path decisions? But that's probably a separate issue; fixing the predicatePushdown test by converting it to JUnit seems like a good move regardless.
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
Re: [jira] Commented: (DERBY-3479) Changed/unexpected query plan
when running test 'lang/predicatePushdown.sql'
Posted by Mike Matrigali <mi...@sbcglobal.net>.
I also scratched my head for awhile, but it turns out unfortunately
compressing a 1 page heap will lead to a 2 page heap. The reason for
this is that compress takes advantage of the generic "bulk loading"
option which applies both to existing and newly created conglomerates,
originally this functionality was built for bulk import of data and then
used for ddl operations like compress which also load a bunch of data.
The main advantage is that no per row logging is necessary when this
is used. The code is not currently special cased for create a new
conglomerate and load it in same operation. So first the new
conglomerate is created and it gets 1 page which has some metadata on it
encoded in the first row on the page. Now for recovery to work right
for the "unlogged" load, load insures that all inserts only happen on
new pages and logs allocation of those new pages. So it first adds a
page to start the inserts and will add subsequent pages . If the load
aborts then the allocations are backed out but will leave the 1st page
untouched.
I will log an improvement request since it should be possible to use the
first page if you know table was created in same transaction as the
load. But it probably isn't that important as a usual user is not going
to run compress unless they have a lot of data. Also subsequent
transactions can insert on the 1st page so the space is not lost forever.
A B (JIRA) wrote:
> [ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575514#action_12575514 ]
>
> A B commented on DERBY-3479:
> ----------------------------
>
> Thanks for the insight, Knut. I don't know much about how it all works, but your theory seems reasonable to me...for what very little that may be worth.
>
>> Aren't all of these tables so small that they should fit on a single page?
>
> I would think so, at least for the first part of the test. I have no idea why that's not the case--nor why compression appears to lead to an *extra* page...
>
> I went ahead and committed d3479_1.diff with svn # 634064:
>
> URL: http://svn.apache.org/viewvc?rev=634064&view=rev
>
> If it turns out the extra page is undesirable and/or the change is not a good one, then the commit can always be backed out.
>
>> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
>> ----------------------------------------------------------------------------
>>
>> Key: DERBY-3479
>> URL: https://issues.apache.org/jira/browse/DERBY-3479
>> Project: Derby
>> Issue Type: Bug
>> Components: Regression Test Failure
>> Affects Versions: 10.4.0.0
>> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
>> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
>> Reporter: Ole Solberg
>> Attachments: d3479_1.diff
>>
>>
>> Seen in tinderbox since r631930.
>> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
>> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
>> 9285 del
>> < Rows seen from the left = 20
>> 9285a9285
>>> Rows seen from the left = 10
>> 9297 del
>> < Rows seen from the right = 20
>> 9297a9297
>>> Rows seen from the right = 10
>> 9299 del
>> < Rows returned = 20
>> 9299a9299
>>> Rows returned = 10
>> .
>> .
>> .
>
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "A B (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575514#action_12575514 ]
A B commented on DERBY-3479:
----------------------------
Thanks for the insight, Knut. I don't know much about how it all works, but your theory seems reasonable to me...for what very little that may be worth.
> Aren't all of these tables so small that they should fit on a single page?
I would think so, at least for the first part of the test. I have no idea why that's not the case--nor why compression appears to lead to an *extra* page...
I went ahead and committed d3479_1.diff with svn # 634064:
URL: http://svn.apache.org/viewvc?rev=634064&view=rev
If it turns out the extra page is undesirable and/or the change is not a good one, then the commit can always be backed out.
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
> Attachments: d3479_1.diff
>
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12574917#action_12574917 ]
Knut Anders Hatlen commented on DERBY-3479:
-------------------------------------------
I also see this failure in my sandbox, but only intermittently. The predicatePushdown test is known to be unstable due to varying query plans (see for instance DERBY-1902). Unless someone can tell that one of the query plans is wrong, I think we should regard it as a test issue, not as a product defect. Rewriting the unstable parts of the test in JUnit and only check the relevant parts of the query plan (that is, whether or not the predicates are pushed down) sounds like a reasonable approach to me.
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Closed: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "Ole Solberg (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Ole Solberg closed DERBY-3479.
------------------------------
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
> Assignee: A B
> Fix For: 10.4.0.0
>
> Attachments: d3479_1.diff
>
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "A B (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575456#action_12575456 ]
A B commented on DERBY-3479:
----------------------------
Some feedback from Mike:
http://article.gmane.org/gmane.comp.apache.db.derby.devel/56229
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575474#action_12575474 ]
Knut Anders Hatlen commented on DERBY-3479:
-------------------------------------------
The buffer manager from DERBY-2911 delegates more of the page cleaning to the background thread. This could perhaps explain why the row count statistics are different. Where the old buffer manager cleans a page synchronously in the user thread and thereby updates the statistics, the new buffer manager may have given the page to the background thread and therefore doesn't update the statistics until a moment later.
Compressing the tables sounds like a good idea, but it does indeed look strange with the extra page. Aren't all of these tables so small that they should fit on a single page?
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
> Attachments: d3479_1.diff
>
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "A B (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
A B updated DERBY-3479:
-----------------------
Attachment: d3479_1.diff
Per Mike's suggestion in the above email, namely:
"solutions include [...] call compress table on all tables before query which will update all statistics and remove dependency on any outstanding per page row count updates"
I updated predicatePushdown.sql to compress all test tables before running any of the queries which expect a specific query plan. When I did that a lot of diffs showed up for predicatePushdown.out in the form of:
- Number of pages visited=1
+ Number of pages visited=2
I.e. seems we now visit one more page than we did without the compress. That seems a tad counter-intuitive to me (I figured compression would make it so that we visited fewer pages), but given my lack of knowledge here I'm assuming that's an okay diff.
With this change I ran predicatePushdown.sql 10 times using ibm15 and it passed every time. I'm not sure how useful that is, though, since this same machine ran 6 times in a row without failing even without this change...
Nonetheless, I'm posting the change as d3479_1.diff in case anyone has comments. I'll probably commit the patch sometime pretty soon since, even if it doesn't resolve this particular issue, it sounds like it's a good idea to compress the tables anyway (per Mike's email)...
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
> Attachments: d3479_1.diff
>
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575619#action_12575619 ]
Knut Anders Hatlen commented on DERBY-3479:
-------------------------------------------
Thanks Army! Compressing the tables seems to have fixed the problem. I've run the test more than 20 times without seeing the failure (before I would see it perhaps 50% of the times).
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
> Attachments: d3479_1.diff
>
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
Re: [jira] Commented: (DERBY-3479) Changed/unexpected query plan
when running test 'lang/predicatePushdown.sql'
Posted by Mike Matrigali <mi...@sbcglobal.net>.
Knut Anders Hatlen (JIRA) wrote:
> [ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575373#action_12575373 ]
>
> Knut Anders Hatlen commented on DERBY-3479:
> -------------------------------------------
>
> I noticed that other tests that depend on stable query plans (wisconsin and StalePlansTest) set derby.storage.checkpointInterval=100000. I tried to add this property to predicatePushdown_derby.properties, and that seemed to stabilize the test.
>
> StalePlansTest contains some magic to flush the row count for the tables. I don't understand exactly what it does, in particular I don't understand why "select count(c1) from flusher" is needed to make the row count for other tables than flusher visible. Perhaps changing the concurrency/timing in the buffer manager somehow changes when the row count is flushed, and thereby it makes the optimizer choose a different plan?
>
>> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
As I remember it, this is how row count estimates work. Delta's are
maintained per page resident in the cache, rather than centralized in
order to not add a single point of contention for every insert/delete in
a table. An update of the single centralized counter is triggered in a
number of ways:
1) language forces the update, usually as a result of doing a full scan
and thus knowing the exact row count.
2) The incremental changes in a single page are "significant", I think
more than 10% of the current row count.
3) When the page is written to disk (see CachedPage!writePage()).
Writes happen either when page is forced from cache as part of
replacement or when a checkpoint happens.
So I think variable query plans in the tests come from:
1) variable row counts because checkpoints take different amounts of
time on different machines. Often the tests do some sort of table setup
in the beginning generating a lot of log and then a checkpoint and then
the checkpoint may be happening in the background while the test has
gotten to the actual query testing phase. I assume the replacement
policy is not variable. So solutions include manipulating checkpoint to
not happen
during test, call offline compress table on all tables before query
which will update all statistics and remove dependency on any
outstanding per page row count updates (offline creates new containers
and recreates indexes/statistics
2) variable amount of time spent in optimizer if query is complicated
enough to stop before costing all plans. Workaround might be to just
set the optimizer to not timeout.
With the .sql tests in my experience often the problem is that we don't
have a reasonable set of test data in the tables, so row estimates off
by 1 actually affect the plan. Usually both plans are reasonable -
usual case is one table on left or right does not actually matter. As
suggested in this case the test probably does not care about most of
the plan, just that the predicate pushdown happened. But it is
sometimes interesting to understand why a new plan is being consistently
chosen as part of new change.
>> ----------------------------------------------------------------------------
>>
>> Key: DERBY-3479
>> URL: https://issues.apache.org/jira/browse/DERBY-3479
>> Project: Derby
>> Issue Type: Bug
>> Components: Regression Test Failure
>> Affects Versions: 10.4.0.0
>> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
>> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
>> Reporter: Ole Solberg
>>
>> Seen in tinderbox since r631930.
>> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
>> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
>> 9285 del
>> < Rows seen from the left = 20
>> 9285a9285
>>> Rows seen from the left = 10
>> 9297 del
>> < Rows seen from the right = 20
>> 9297a9297
>>> Rows seen from the right = 10
>> 9299 del
>> < Rows returned = 20
>> 9299a9299
>>> Rows returned = 10
>> .
>> .
>> .
>
[jira] Commented: (DERBY-3479) Changed/unexpected query plan when
running test 'lang/predicatePushdown.sql'
Posted by "Knut Anders Hatlen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/DERBY-3479?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12575373#action_12575373 ]
Knut Anders Hatlen commented on DERBY-3479:
-------------------------------------------
I noticed that other tests that depend on stable query plans (wisconsin and StalePlansTest) set derby.storage.checkpointInterval=100000. I tried to add this property to predicatePushdown_derby.properties, and that seemed to stabilize the test.
StalePlansTest contains some magic to flush the row count for the tables. I don't understand exactly what it does, in particular I don't understand why "select count(c1) from flusher" is needed to make the row count for other tables than flusher visible. Perhaps changing the concurrency/timing in the buffer manager somehow changes when the row count is flushed, and thereby it makes the optimizer choose a different plan?
> Changed/unexpected query plan when running test 'lang/predicatePushdown.sql'
> ----------------------------------------------------------------------------
>
> Key: DERBY-3479
> URL: https://issues.apache.org/jira/browse/DERBY-3479
> Project: Derby
> Issue Type: Bug
> Components: Regression Test Failure
> Affects Versions: 10.4.0.0
> Environment: OS: Solaris 10 6/06 s10x_u2wos_09a X86 64bits - SunOS 5.10 Generic_118855-14
> JVM: Sun Microsystems Inc., java version "1.6.0_04", Java(TM) SE Runtime Environment (build 1.6.0_04-b12), Java HotSpot(TM) Client VM (build 10.0-b19, mixed mode)
> Reporter: Ole Solberg
>
> Seen in tinderbox since r631930.
> See e.g. http://dbtg.thresher.com/derby/test/tinderbox_trunk16/jvm1.6/testing/testlog/SunOS-5.10_i86pc-i386/631932-derbyall_diff.txt :
> *** Start: predicatePushdown jdk1.6.0_04 derbyall:derbylang 2008-02-28 14:02:49 ***
> 9285 del
> < Rows seen from the left = 20
> 9285a9285
> > Rows seen from the left = 10
> 9297 del
> < Rows seen from the right = 20
> 9297a9297
> > Rows seen from the right = 10
> 9299 del
> < Rows returned = 20
> 9299a9299
> > Rows returned = 10
> .
> .
> .
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.