Runtime statistics not collected on re-execution of statement

• Key: DERBY-4204
• Type: Bug
• Status: Closed
• Resolution: Fixed
• Priority: Minor
• Assignee: Knut Anders Hatlen
• Reporter: Knut Anders Hatlen
• Component/s: SQL
• Affects Version/s: 10.3.1.4
• Fix Version/s: 10.5.2.0, 10.6.0.0

Description

Runtime statistics are only collected the first time an insert/update/delete statement is executed. The behaviour changed between Derby 10.2.2.0 and Derby 10.3.1.4, so this was likely introduced by DERBY-827.

Reported on derby-dev:
http://mail-archives.apache.org/mod_mbox/db-derby-dev/200904.mbox/[e-mail]%3e

Comments

[Knut Anders Hatlen]

Here's a script that reproduces the problem.

With Derby 10.2.2.0, the last call to syscs_get_runtimestatistics returns the following:

Statement Name:
null
Statement Text:
insert into t values 1
.
.
.

With 10.3.1.4 (and later), it returns this:

Statement Name:
null
Statement Text:
values syscs_util.syscs_get_runtimestatistics()
.
.
.


The behaviour in 10.2.2.0 is the expected one, since the insert statement was the last one to be executed before syscs_get_runtimestatistics was called.

Re-execution of select statements appears to work as expected.

[Knut Anders Hatlen]

Attached is a patch that adds JUnit test cases that test collection of runtime statistics for SELECT, UPDATE, INSERT, DELETE, VALUES and CALL when re-executing a prepared statement. The test cases for SELECT and VALUES pass, the rest of them fail.

[Bryan Pendleton]

In the trunk, it would be neat if we could write a test case for this using the new XPLAIN tables feature.

I don't think we want to do that for the base patch because it would then be hard to back-port the
patch to 10.5 and earlier.

But if you let me know when you're done with the basic patch, I'll try writing a separate test-only
patch for the trunk which uses the XPLAIN tables feature to confirm this fix.

[Knut Anders Hatlen]

Good idea, Bryan. I tested it in ij and saw that re-execution of a prepared insert statement resulted in only one row in SYSXPLAIN_STATEMENTS, whereas re-execution of a prepared select statement resulted in one row per execution, so it should be possible to test this bug with the XPLAIN tables too.

[Knut Anders Hatlen]

First I thought we should reset the NoRowsResultSetImpl's dumpedStats flag, either in close() or when reopening the result set. But when I looked closer, I noticed that dumpedStats is only ever used in close(), and close() is short-circuited before we dump the stats if close() is called again before the result set is reopened. So I think we could just as well remove the flag and rely on the isOpen flag to protect against dumping the same stats multiple times.

The attached patch (d4204.diff) removes the dumpedStats flag and makes close() always dump the stats if the result set is open. It also adds regression tests for this bug.

All the regression tests passed.

[Knut Anders Hatlen]

Committed the patch to trunk with revision 774281.

Bryan, it should be OK to add a regression test based on XPLAIN to trunk now, either as part of this issue or as a separate issue.

I'll leave this issue open until the fix has been backported.

[Bryan Pendleton]

Attached 'addXPLAINTest.diff' is a patch proposal which augments the test
that Knut added to additionally verify that the SYSXPLAIN_STATEMENTS
table sees 5 distinct rows when the statement is executed 5 times.

I verified (by re-introducing the bug in my environment) that prior to the
fix, the UPDATE, DELETE, and INSERT statements only saw 1 row in SYSXPLAIN_STATEMENTS,
while the SELECT and VALUES statements saw 5 rows, while with the
code change in place, all the statements capture 5 rows into SYSXPLAIN_STATEMENTS.

As opposed to the rest of the DERBY-4204 fix, this change should NOT be backported
to prior branches, because the XPLAIN tables feature is only present in the trunk.

Please let me know of any comments on the patch. If it seems OK, I'll commit it to the trunk.

[Bryan Pendleton]

Revised the new test slightly to make it more compact, by issuing
a COUNT query and using JDBC.assertFullResultSet to check the result.

[Knut Anders Hatlen]

Thanks for writing the test, Bryan! The test looks much better now that the boilerplate is removed. +1 to commit.

(One microscopic nit: assertSingleValueResultSet() would simplify the code slightly compared to assertFullResultSet(). And there's a typo in a comment: s/caputured/captured/)

[Bryan Pendleton]

Committed the revised test to the trunk as svn revision 774830. I'm not intending to do any further work on this issue.

[Knut Anders Hatlen]

Merged the fix to the 10.5 branch and committed revision 774831.

This fix is a candidate for back-porting to 10.4 and 10.3 as well since it's a regression. However, the test case doesn't compile since it uses a helper method not present on the 10.4 branch, so some manual intervention is needed in order to back-port it all the way.

[Knut Anders Hatlen]

Marking the issue as resolved since the fix has been committed to trunk and to the 10.5 branch.