Incorrect Runtime Statistics

[JR <jl...@gmail.com>]

I checked out and built the 10.4 branch and am seeing inconsistent
results when requesting the runtime statistics for a prepared
statement. I've tracked it down to the "isTopResultSet" check in the
NoPutResultSetImpl.close() method. It seems that "isTopResultSet"
doesn't get changed for the second (and subsequent) executions of
insert and delete statements. This causes the runtime statistics
update logic to be skipped and will return the stats for the wrong
statement.

I'm including the test that I'm using the verify this behavior. I've
omitted the setup/teardown parts for brevity but I can provide the
full source if it will help. The test fails in the second call to
assertCorrectStatistics() at the call to assertFalse() because the
statistics are for the call to GET_RUNTIMESTATISTICS().

Thanks for any help you can provide.

    private static final String GET_RUNTIMESTATISTICS_QUERY = "VALUES
SYSCS_UTIL.SYSCS_GET_RUNTIMESTATISTICS()";
    private static final String ENABLE_RUNTIMESTATISTICS_CALL = "CALL
SYSCS_UTIL.SYSCS_SET_RUNTIMESTATISTICS(1)";
    private static final String ENABLE_TIMING_CALL = "CALL
SYSCS_UTIL.SYSCS_SET_STATISTICS_TIMING(1)";
    private static final String CREATE_TABLE = "CREATE TABLE
TEST_TABLE (dummy varchar(1))";
    private static final String DROP_TABLE = "DROP TABLE TEST_TABLE";
    private static final String INSERT_STATEMENT = "INSERT INTO
TEST_TABLE (dummy) VALUES('a')";

    public void testSimpleInsert() throws SQLException {
        Connection conn = DATA_SOURCE.getConnection();
        final PreparedStatement insertStatement =
conn.prepareStatement(INSERT_STATEMENT);

        String stats = null;
        try {
            enableStatistics(conn);

            assertEquals(1, insertStatement.executeUpdate());
            stats = getRuntimeStatistics(conn);
            assertCorrectStatistics(stats, INSERT_STATEMENT);

            assertEquals(1, insertStatement.executeUpdate());
            stats = getRuntimeStatistics(conn);
            assertCorrectStatistics(stats, INSERT_STATEMENT); // FAILS!
        } finally {
            insertStatement.close();
            conn.close();
        }
    }

    private static void assertCorrectStatistics(String stats, String
expectedString) {
        assertNotNull(stats);
        assertFalse("Returned statistics for incorrect statement.", stats
                .contains(GET_RUNTIMESTATISTICS_QUERY));
        assertTrue("Expected string not found in statistics.",
stats.contains(expectedString));
    }

    private static String getRuntimeStatistics(Connection conn) throws
SQLException {
        PreparedStatement planStatement =
conn.prepareStatement(GET_RUNTIMESTATISTICS_QUERY);
        String stats = null;
        ResultSet results = null;
        try {
            results = planStatement.executeQuery();
            results.next();
            stats = results.getString(1);
        } finally {
            if (results != null)
                results.close();
            planStatement.close();
        }
        return stats;
    }

Re: Incorrect Runtime Statistics

[JR <jl...@gmail.com>]

Thanks for quick turnaround and for logging the bug. I confirmed that
10.2.2.0 works as expected and look forward to seeing the fix in the
next release. Thanks again.

Jared Roberts

On Thu, Apr 30, 2009 at 3:23 AM, Knut Anders Hatlen <Kn...@sun.com> wrote:
> Knut Anders Hatlen <Kn...@Sun.COM> writes:
>
>> I'm wondering if the problem you're seeing is a side-effect of
>> DERBY-827. Before, a new result set would be created each time a
>> statement was re-executed, so all the flags were implicitly reset on
>> re-execution. Now, the result set objects are reused (which
>> significantly improved the performance) and that means that variables
>> must be reset explicitly between executions. DERBY-827 was fixed in
>> 10.3.1.4, and I actually see the behaviour you're describing in that
>> version, whereas 10.2.2.0 behaves as expected. I'll file a bug report.
>
> Logged: https://issues.apache.org/jira/browse/DERBY-4204
>
> --
> Knut Anders
>

Re: Incorrect Runtime Statistics

[Knut Anders Hatlen <Kn...@Sun.COM>]

Knut Anders Hatlen <Kn...@Sun.COM> writes:

> I'm wondering if the problem you're seeing is a side-effect of
> DERBY-827. Before, a new result set would be created each time a
> statement was re-executed, so all the flags were implicitly reset on
> re-execution. Now, the result set objects are reused (which
> significantly improved the performance) and that means that variables
> must be reset explicitly between executions. DERBY-827 was fixed in
> 10.3.1.4, and I actually see the behaviour you're describing in that
> version, whereas 10.2.2.0 behaves as expected. I'll file a bug report.

Logged: https://issues.apache.org/jira/browse/DERBY-4204

-- 
Knut Anders

Re: Incorrect Runtime Statistics

[Knut Anders Hatlen <Kn...@Sun.COM>]

JR <jl...@gmail.com> writes:

> I checked out and built the 10.4 branch and am seeing inconsistent
> results when requesting the runtime statistics for a prepared
> statement. I've tracked it down to the "isTopResultSet" check in the
> NoPutResultSetImpl.close() method. It seems that "isTopResultSet"
> doesn't get changed for the second (and subsequent) executions of
> insert and delete statements. This causes the runtime statistics
> update logic to be skipped and will return the stats for the wrong
> statement.

Hi,

I'm wondering if the problem you're seeing is a side-effect of
DERBY-827. Before, a new result set would be created each time a
statement was re-executed, so all the flags were implicitly reset on
re-execution. Now, the result set objects are reused (which
significantly improved the performance) and that means that variables
must be reset explicitly between executions. DERBY-827 was fixed in
10.3.1.4, and I actually see the behaviour you're describing in that
version, whereas 10.2.2.0 behaves as expected. I'll file a bug report.

Thanks,

-- 
Knut Anders