Issue Details (XML | Word | Printable)

Key: DERBY-2584
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Major Major
Assignee: Knut Anders Hatlen
Reporter: Bernt M. Johnsen
Votes: 0
Watchers: 0
Operations

If you were logged in you would be able to see more operations.
Derby

Creating a database with JPOX SchemaTool sometimes gives ArrayIndexOutOfBoundsException when getIndexInfo() is called

Created: 24/Apr/07 08:25 AM   Updated: 10/May/07 11:17 AM
Return to search
Component/s: SQL
Affects Version/s: 10.2.1.6, 10.2.2.0, 10.3.1.4
Fix Version/s: 10.2.2.1, 10.3.1.4

Time Tracking:
Not Specified

File Attachments:
  Size
Java Source File Licensed for inclusion in ASF works d2584.java 2007-05-07 03:13 PM Knut Anders Hatlen 0.9 kB
File Licensed for inclusion in ASF works derby-2584-v1.diff 2007-05-09 09:07 AM Knut Anders Hatlen 4 kB
File Licensed for inclusion in ASF works derby-2584-v1.stat 2007-05-09 09:07 AM Knut Anders Hatlen 0.2 kB
File Licensed for inclusion in ASF works initiallyCompilable.diff 2007-05-08 02:57 PM Knut Anders Hatlen 0.7 kB
Issue Links:
Reference

Resolution Date: 09/May/07 01:33 PM


 Description  « Hide
It has been reported (e.g. here: http://www.jpox.org/servlet/forum/viewthread?thread=4034 ) that the database sometimes get corrupt when the db is created with JPOX SchemaTool. This leads to java.lang.ArrayIndexOutOfBoundsException for some (at least one: getIndexInfo) metadata calls. When this happens, the types array GenericParameterValueSet.initialize has length 0.

I have not yet managed to reproduce the bug in a small repro. A workaround exists though: Create the database before you run the JPOX SchemaTool.

The stack trace you get when getIndexInfo is called is

2007-04-17 16:20:20.191 GMT Thread[DRDAConnThread_5,5,main] (XID = 1554), (SESSIONID = 10), (DATABASE = communitymc_portal1), (DRDAID = C0124DC3.H92B-954198994222304164{11}), Failed Statement is: CALL SYSIBM.SQLSTATISTICS(?,?,?,?,?,?) with 6 parameters begin parameter #1: null :end parameter begin parameter #2: PORTAL :end parameter begin parameter #3: COMMUNITY :end parameter begin parameter #4: 1 :end parameter begin parameter #5: 1 :end parameter begin parameter #6: DATATYPE='JDBC';DYNAMIC=0;REPORTPUBLICPRIVILEGES=1;CURSORHOLD=1 :end parameter
java.lang.ArrayIndexOutOfBoundsException: 0
        at org.apache.derby.impl.sql.GenericParameterValueSet.initialize(Unknown Source)
        at org.apache.derby.impl.sql.execute.BaseActivation.setupActivation(Unknown Source)
        at org.apache.derby.impl.sql.GenericActivationHolder.<init>(Unknown Source)
        at org.apache.derby.impl.sql.GenericPreparedStatement.getActivation(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement.<init>(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement20.<init>(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement30.<init>(Unknown Source)
        at org.apache.derby.jdbc.Driver30.newEmbedPreparedStatement(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedConnection.prepareMetaDataStatement(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.prepareSPS(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQueryUsingSystemTables(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getPreparedQuery(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.doGetIndexInfo(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedDatabaseMetaData.getIndexInfo(Unknown Source)
        at org.apache.derby.catalog.SystemProcedures.SQLSTATISTICS(Unknown Source)
        at org.apache.derby.exe.ac72e9c096x0112x0056x2b09xffffcd3424e39.g0(Unknown Source)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.apache.derby.impl.services.reflect.ReflectMethod.invoke(Unknown Source)
        at org.apache.derby.impl.sql.execute.CallStatementResultSet.open(Unknown Source)
        at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedCallableStatement.executeStatement(Unknown Source)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement.execute(Unknown Source)
        at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
        at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown Source)
        at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown Source)
        at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown Source)
        at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)


 All   Comments   Work Log   Change History   Subversion Commits      Sort Order: Ascending order - Click to sort in descending order
Mike Matrigali added a comment - 06/May/07 09:51 PM
From reading the comments it looks like the db boots fine, but there is a persistent problem with some set of the metadata calls.

Bernt M. Johnsen added a comment - 07/May/07 11:34 AM
The described workaround does not always solve the problem.

Bernt M. Johnsen added a comment - 07/May/07 11:36 AM
The bug is apparently inrouduced after we have had a 20 seconds hang (a lock timeout?) like the ones described in DERBY-177 and DERBY-1996.

Bernt M. Johnsen added a comment - 07/May/07 11:36 AM
Might be related to DERBY-1996

Knut Anders Hatlen added a comment - 07/May/07 03:13 PM
The attached java file (d2584.java) contains a simple repro for this error. What it does is:

  1) create a new database
  2) open a connection in repeatable read, auto-commit off
  3) select * from sys.sysstatements
  4) call DatabaseMetaData.getIndexInfo() -> this will hang for derby.locks.waitTimeout seconds and return successfully
  5) call DatabaseMetaData.getIndexInfo() again -> this will throw ArrayIndexOutOfBoundsException

I have verified that this fails consistently on 10.2.1.6, 10.2.2.0 and trunk. It does however not fail on 10.0.2.1 and 10.1.3.1.

Knut Anders Hatlen added a comment - 08/May/07 02:57 PM
I don't know exactly what's happening, but it seems like an attempt to store the SPS for getIndexInfo() in a nested transaction fails because the parent transaction holds a shared lock on SYSSTATEMENTS. Therefore, an attempt is made to store the SPS in the parent transaction, and that succeeds. However, the SPS that is stored is not complete, so the next call to getIndexInfo() fails.

SPSDescriptor.updateSYSSTATEMENTS() and DataDictionaryImpl.updateSPS() have some logic to ensure that parts of the stored statement are only updated the first time the statement is prepared. But since the first failed attempt in the nested transaction is counted as the first compile, the update in the main transaction does not update everything correctly.

The attached patch restores some of the state (one boolean field--initiallyCompilable) when the first update times out, so that the update in the main transaction is regarded as the first compilation. This makes the repro run without errors. Does this sound like a reasonable approach? I have not run any tests yet.

Knut Anders Hatlen added a comment - 08/May/07 09:28 PM
Derbyall and suites.All ran cleanly with initiallyCompilable.diff. I'll see if I can add some comments and a test case to it.

Knut Anders Hatlen added a comment - 09/May/07 09:07 AM
Uploaded a new patch which adds a comment about the fix and a JUnit test case that fails without the fix. The patch is ready for review.

Bernt M. Johnsen added a comment - 09/May/07 09:55 AM
Patch looks good. Thanks! Tested on trunk, and the patched solved the corruption problem (although the deadlock (DERBY-177) is still there).

Øystein Grøvlen added a comment - 09/May/07 10:02 AM
Patch looks good. I have run the JPOX schema creation tool and the patch fixes the failure.

Bernt M. Johnsen added a comment - 09/May/07 11:05 AM
There are 3 Possible workarounds for this bug:

1) Make JPOX SchemaTool run with READ_COMMITTED (the bug wil only
   happen for REPEATABLE_READ (or higher?).

2) Make JPOX SchemaTool run in autocommit moed (if that's feasible).

3) Create the database before you run SchemaTool with code like this:

        Connection c = DriverManager.getConnection(url);
        DatabaseMetaData dmd = c.getMetaData();
        dmd.getIndexInfo("","","",false,false);
        dmd.getExportedKeys("","","");
        dmd.getImportedKeys("","","");
        c.close();

   This is for SchemaTool in JPOX 1.1.0. If additional metadata calls
   is needed, you will easily see that in the stackTrace you get from
   the bug.

Knut Anders Hatlen added a comment - 09/May/07 01:33 PM
Thanks Bernt and Øystein for reviewing and testing the patch.
Committed to trunk with revision 536516.
Committed to 10.2 with revision 536517.

Bernt M. Johnsen added a comment - 10/May/07 09:04 AM
Verified.

Bernt M. Johnsen added a comment - 10/May/07 11:17 AM
Another possible workaround, avaialble for JPOX 1.1.1 and later: Write an extension to DerbyAdapter implementing

    public int getTransactionIsolationForSchemaCreation()
    {
        return Connection.TRANSACTION_READ_COMMITTED;
    }

Read http://www.jpox.org/docs/1_1/extensions/datastore_adapter.html on how to plug in the new adapter.