Derby
  1. Derby
  2. DERBY-4264

highly intermittent java.lang.ClassCastException: [[Lorg.apache.derby.iapi.store.access.Qualifier; incompatible with org.apache.derby.iapi.types.DataValueDescriptor doing simple select

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 10.2.2.0
    • Fix Version/s: None
    • Component/s: SQL
    • Environment:
      Embedded Derby 10.2.2.0 - (485682)
      z/OS J2RE 1.5.0 IBM z/OS build pmz31dev-20081210 (SR9-0)
    • Urgency:
      Normal
    • Bug behavior facts:
      Seen in production

      Description

      I got a report from a user for a highly intermittent ClassCastException doing a select. Below is the stack trace:
      java.lang.ClassCastException:
      [[Lorg.apache.derby.iapi.store.access.Qualifier; incompatible
      with org.apache.derby.iapi.types.DataValueDescriptor
      at
      org.apache.derby.impl.sql.execute.GenericQualifier.getOrderable(
      Unknown Source)
      at
      org.apache.derby.impl.sql.execute.NoPutResultSetImpl.clearOrdera
      bleCache(Unknown Source)
      at
      org.apache.derby.impl.sql.execute.BulkTableScanResultSet.openSca
      nController(Unknown Source)
      at
      org.apache.derby.impl.sql.execute.TableScanResultSet.openCore(Un
      known Source)
      at
      org.apache.derby.impl.sql.execute.BulkTableScanResultSet.openCor
      e(Unknown Source)
      at
      org.apache.derby.impl.sql.execute.BasicNoPutResultSetImpl.open(U
      nknown Source)
      at
      org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unkno
      wn Source)
      at
      org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unkno
      wn Source)
      at org.apache.derby.impl.jdbc.EmbedStatement.execute(Unknown
      Source)
      at
      org.apache.derby.impl.jdbc.EmbedStatement.executeQuery(Unknown
      Source)

      I don't have a reproduction yet but have some information on the schema and query that occasionally fails: The data here is contrived, I don't know the actual data in the table at the time of the failure. The column names have changed, but represent the same types.

      CREATE TABLE "APP"."RESOURCE"
      (
      "AUUID" CHAR(36) NOT NULL,
      "BUUID" CHAR(36) NOT NULL,
      "CUUID" CHAR(36) NOT NULL,
      "DUUID" CHAR(36) NOT NULL,
      "SECTION" CHAR(6) NOT NULL,
      "TYPE" CHAR(48) NOT NULL,
      "LASTUPDATE" TIMESTAMP NOT NULL
      );
      ALTER TABLE "APP"."RESOURCE" ADD CONSTRAINT "SQL060817095529130" PRIMARY KEY ("AUUID", "BUUID", "SECTION");

      – Not sure of the actual data. This data was made up so the query would get a match.

      INSERT INTO RESOURCE VALUES ('3b2c2edc-1401-0000-0080-c38634aef3ba', '3b2c2edc-1401-0000-0080-c38634aef3bb', '2be1347d-2001-0000-0080-8cd524f0d034', '2be1347d-2001-0000-0080-8cd524f0d033', 'GENRAL', 'NodeType', CURRENT_TIMESTAMP);

      SELECT * FROM RESOURCE WHERE
      SECTION='GENRAL' AND
      TYPE='NodeType' AND
      DUUID='2be1347d-2001-0000-0080-8cd524f0d033' AND
      BUUID='3b2c2edc-1401-0000-0080-c38634aef3bb';

      This has happened to just one user on z/OS with J2RE 1.5.0 IBM z/OS build pmz31dev-20081210 (SR9-0). Other users running the same application on the same versions have not seen this issue. This particular user has disabled the functionality causing the problem for now, so I am hoping we can glean some information from code inspection and debugging this sample query to see where the cast might go wrong.

      1. acf81e0010x0121xcb69x9b94x0000000eb0100.java
        5 kB
        Kathey Marsden
      2. derby-4264_10.2_diag_diff.txt
        13 kB
        Kathey Marsden
      3. derby-4264_10.2_diag_diff.txt
        11 kB
        Kathey Marsden

        Activity

        Hide
        Knut Anders Hatlen added a comment -

        [bulk update] Close all resolved issues that haven't been updated for more than one year.

        Show
        Knut Anders Hatlen added a comment - [bulk update] Close all resolved issues that haven't been updated for more than one year.
        Hide
        Kathey Marsden added a comment -

        Closing cannot reproduce as we have not heard back from the user with the problem for some time. I am not sure of the final resolution. It can be reopened if encountered again.

        Show
        Kathey Marsden added a comment - Closing cannot reproduce as we have not heard back from the user with the problem for some time. I am not sure of the final resolution. It can be reopened if encountered again.
        Hide
        Kathey Marsden added a comment -

        There is another user seeing this issue with 10.2 on z/OS with this jvm
        java version "1.5.0"

        Java(TM) 2 Runtime Environment, Standard Edition (build
        pmz31devifx-20090129 (SR9-1))

        IBM J9 VM (build 2.3, J2RE 1.5.0 IBM J9 2.3 z/OS s390-31
        j9vmmz3123ifx-20090128 (JIT enabled)
        J9VM - 20090126_28859_bHdSMr
        JIT - 20081112_1511ifx1_r8
        GC - 200811_07)
        JCL - 20090128

        They have a fairly reliable reproduction at the site and have found that it does not reproduce with JIT off. There is a service refresh 11 available for IBM 1.5 on z/OS so I suggested that they upgrade and then try JIT diagnostics to narrow down the issue.
        http://publib.boulder.ibm.com/infocenter/javasdk/v6r0/topic/com.ibm.java.doc.diagnostics.60/diag/tools/jitpd_failing_method.html?resultof=%22%66%61%69%6c%69%6e%67%22%20%22%66%61%69%6c%22%20%22%6d%65%74%68%6f%64%22%20

        Show
        Kathey Marsden added a comment - There is another user seeing this issue with 10.2 on z/OS with this jvm java version "1.5.0" Java(TM) 2 Runtime Environment, Standard Edition (build pmz31devifx-20090129 (SR9-1)) IBM J9 VM (build 2.3, J2RE 1.5.0 IBM J9 2.3 z/OS s390-31 j9vmmz3123ifx-20090128 (JIT enabled) J9VM - 20090126_28859_bHdSMr JIT - 20081112_1511ifx1_r8 GC - 200811_07) JCL - 20090128 They have a fairly reliable reproduction at the site and have found that it does not reproduce with JIT off. There is a service refresh 11 available for IBM 1.5 on z/OS so I suggested that they upgrade and then try JIT diagnostics to narrow down the issue. http://publib.boulder.ibm.com/infocenter/javasdk/v6r0/topic/com.ibm.java.doc.diagnostics.60/diag/tools/jitpd_failing_method.html?resultof=%22%66%61%69%6c%69%6e%67%22%20%22%66%61%69%6c%22%20%22%6d%65%74%68%6f%64%22%20
        Hide
        Dag H. Wanvik added a comment -

        Triaged for 10.5.2, checking "seen in production" and setting "normal" urgency.

        Show
        Dag H. Wanvik added a comment - Triaged for 10.5.2, checking "seen in production" and setting "normal" urgency.
        Hide
        Knut Anders Hatlen added a comment -

        You're right, the back-pointers don't make much sense for DirectCall. We'll know which of the e* methods is being called, and also which Activation/GeneratedByteCode it was called on, so it should be easy to see if the method actually did return a Qualifier[][]. I don't see any more useful information that's easily available at this point. It's probably better to wait for the diagnostics from this patch before adding more instrumentation, as you'll probably know more about what to look for then.

        Show
        Knut Anders Hatlen added a comment - You're right, the back-pointers don't make much sense for DirectCall. We'll know which of the e* methods is being called, and also which Activation/GeneratedByteCode it was called on, so it should be easy to see if the method actually did return a Qualifier[][]. I don't see any more useful information that's easily available at this point. It's probably better to wait for the diagnostics from this patch before adding more instrumentation, as you'll probably know more about what to look for then.
        Hide
        Kathey Marsden added a comment - - edited

        Thank you Knut for looking at htis.

        Attached is an updated diff with the ReflectMethod.toString() and the backpointer to the RGC for ReflectMethod.

        I did find that the query in question (and it seems all queries) use DirectCall when passing through the GenericQualifier code and not ReflectMethod. I could only seem to go through the ReflectMethod code with a CALL statement (CallableStatementNode) which is not relevant to this issue, but it is good to be prepared for any eventuality since I am so clueless as to the root cause.

        For DirectCall I am not sure how to handle the back pointers because DirectCall is only used in the static array directs in ReflectGeneratedClass and then these ten DirectCalls are reused for all classes. At the point that we get back the wrong type I don't think I can back track and find out what class was associated when the reference was made. Do you know the best way to do this? I guess ReflectGeneratedClass.getMethod() could take the activation and then new up a DirectCall and pass it along instead of using the static array. Then in DirectCall.invoke we can check that it matches the reference passed to invoke. Would that be practical?
        I don't want to change things so much that we no longer expose the bug.

        Show
        Kathey Marsden added a comment - - edited Thank you Knut for looking at htis. Attached is an updated diff with the ReflectMethod.toString() and the backpointer to the RGC for ReflectMethod. I did find that the query in question (and it seems all queries) use DirectCall when passing through the GenericQualifier code and not ReflectMethod. I could only seem to go through the ReflectMethod code with a CALL statement (CallableStatementNode) which is not relevant to this issue, but it is good to be prepared for any eventuality since I am so clueless as to the root cause. For DirectCall I am not sure how to handle the back pointers because DirectCall is only used in the static array directs in ReflectGeneratedClass and then these ten DirectCalls are reused for all classes. At the point that we get back the wrong type I don't think I can back track and find out what class was associated when the reference was made. Do you know the best way to do this? I guess ReflectGeneratedClass.getMethod() could take the activation and then new up a DirectCall and pass it along instead of using the static array. Then in DirectCall.invoke we can check that it matches the reference passed to invoke. Would that be practical? I don't want to change things so much that we no longer expose the bug.
        Hide
        Knut Anders Hatlen added a comment -

        Hi Kathey,

        I don't see that you added a toString() method in ReflectMethod. Did you conclude that the generated method would always have to be a DirectCall?

        Perhaps it would also be useful to add back-pointers from DirectCall/ReflectMethod to their parent ReflectGeneratedClass and include that info in toString(). Then we would detect if there's a mismatch between the method's RGC and the activation's RGC (which will be printed in dumpClassFile()).

        Show
        Knut Anders Hatlen added a comment - Hi Kathey, I don't see that you added a toString() method in ReflectMethod. Did you conclude that the generated method would always have to be a DirectCall? Perhaps it would also be useful to add back-pointers from DirectCall/ReflectMethod to their parent ReflectGeneratedClass and include that info in toString(). Then we would detect if there's a mismatch between the method's RGC and the activation's RGC (which will be printed in dumpClassFile()).
        Hide
        Kathey Marsden added a comment -

        The attached diff derby-4264_10.2_diag_diff.txt has the 10.2 diagnostic changes that that I plan to send to the user that is seeing this issue. They now have a test system where they can reproduce the failure after several days run and will run with this sane modified build.

        This is not for commit. The change will dump the class file and information about the GeneratedMethod and the object returned if orderableGetter.invoke(activation) returns an unexpected type object. It also can be run with derby.debug.true=DERBY-4264_Always to always dump this information even if the expected type is returned. Sample output in derby.log looks something like:
        DEBUG orderableGetterInvoke(),orderableGetter OUTPUT: DirectCall: which=1(e1())

        DEBUG orderableGetterInvoke(), orderableCacheObject OUTPUT: org.apache.derby.iapi.types.SQLChar:2be1347d-2001-0000-0080-8cd524f0d033

        DEBUG orderableGetterInvoke(), this OUTPUT: columnId: 3
        operator: 2
        orderedNulls: false
        unknownRV: false
        negateCompareResult: false
        variantType: 3

        DEBUG ReflectGeneratedClass this.toString() OUTPUT:
        ReflectGeneratedClass.getName()=org.apache.derby.exe.ac601a400fx0122x1f0dx1cdax0000001f2c580
        factoryClass=null

        2009-06-27 00:11:09.500 GMT Thread[main,5,main] Wrote class org.apache.derby.exe.ac601a400fx0122x1f0dx1cdax0000001f2c580 to file .\ac601a400fx0122x1f0dx1cdax0000001f2c580.class

        In order to dump the class file at this late point in processing I had to pass the ByteArray for the class data to LoadGeneratedClass when it is created so that the ByteArray is preserved. ( I didn't know how to get the byte code back out after it had been converted to a class with defineClass. If the problem is actually in the conversion then we won't see that unless we can figure out a way to retreive the byte code directly from the class.

        Please take a look and let me know if there is anything else useful that we could print out to help diagnose this issue. There is some significant effort and time associated with getting a run so I want to avoid additional round trips if possible.

        Show
        Kathey Marsden added a comment - The attached diff derby-4264_10.2_diag_diff.txt has the 10.2 diagnostic changes that that I plan to send to the user that is seeing this issue. They now have a test system where they can reproduce the failure after several days run and will run with this sane modified build. This is not for commit. The change will dump the class file and information about the GeneratedMethod and the object returned if orderableGetter.invoke(activation) returns an unexpected type object. It also can be run with derby.debug.true= DERBY-4264 _Always to always dump this information even if the expected type is returned. Sample output in derby.log looks something like: DEBUG orderableGetterInvoke(),orderableGetter OUTPUT: DirectCall: which=1(e1()) DEBUG orderableGetterInvoke(), orderableCacheObject OUTPUT: org.apache.derby.iapi.types.SQLChar:2be1347d-2001-0000-0080-8cd524f0d033 DEBUG orderableGetterInvoke(), this OUTPUT: columnId: 3 operator: 2 orderedNulls: false unknownRV: false negateCompareResult: false variantType: 3 DEBUG ReflectGeneratedClass this.toString() OUTPUT: ReflectGeneratedClass.getName()=org.apache.derby.exe.ac601a400fx0122x1f0dx1cdax0000001f2c580 factoryClass=null 2009-06-27 00:11:09.500 GMT Thread [main,5,main] Wrote class org.apache.derby.exe.ac601a400fx0122x1f0dx1cdax0000001f2c580 to file .\ac601a400fx0122x1f0dx1cdax0000001f2c580.class In order to dump the class file at this late point in processing I had to pass the ByteArray for the class data to LoadGeneratedClass when it is created so that the ByteArray is preserved. ( I didn't know how to get the byte code back out after it had been converted to a class with defineClass. If the problem is actually in the conversion then we won't see that unless we can figure out a way to retreive the byte code directly from the class. Please take a look and let me know if there is anything else useful that we could print out to help diagnose this issue. There is some significant effort and time associated with getting a run so I want to avoid additional round trips if possible.
        Hide
        Kathey Marsden added a comment -

        Since I have not been able to reproduce this issue and don't see how we could return a Qualifier[][] in this context, I would like to give the user a diagnostic build to try to catch the ClassCastException and dump the generated class if it occurs.

        I am not quite sure how to do this from this context. I will keep working on it, but any ideas are welcome.

        Is there other information that might be useful if the error occurs?

        Kathey

        Show
        Kathey Marsden added a comment - Since I have not been able to reproduce this issue and don't see how we could return a Qualifier[][] in this context, I would like to give the user a diagnostic build to try to catch the ClassCastException and dump the generated class if it occurs. I am not quite sure how to do this from this context. I will keep working on it, but any ideas are welcome. Is there other information that might be useful if the error occurs? Kathey
        Hide
        Kathey Marsden added a comment -

        Attached is the decompiled class from the query. The methods being invoked are e1(), e2(), e3() and e4() which all return
        return datavaluefactory.getCharDataValue(string, null);
        for the four different strings in our predicates.

        There's no place in this code where a Qualifier[][] would be returned.

        Looking at the places where we return a Qualifier[][] in generated code, the most likely suspect to me is in PredicateList.generateQualifiers()

        I do see us going through that method with our query but don't immediately see that generated code in the decompiled class. I will investigate further ...

        Show
        Kathey Marsden added a comment - Attached is the decompiled class from the query. The methods being invoked are e1(), e2(), e3() and e4() which all return return datavaluefactory.getCharDataValue(string, null); for the four different strings in our predicates. There's no place in this code where a Qualifier[][] would be returned. Looking at the places where we return a Qualifier[][] in generated code, the most likely suspect to me is in PredicateList.generateQualifiers() I do see us going through that method with our query but don't immediately see that generated code in the decompiled class. I will investigate further ...
        Hide
        Mike Matrigali added a comment -

        For description of why 2d Qualifiers are passed around see the javadoc in the following file:
        opensource/java/engine/org/apache/derby/iapi/store/access/Qualifier.java

        the short answer is that it is a way of encoding and's and or's of qualifiers.

        Show
        Mike Matrigali added a comment - For description of why 2d Qualifiers are passed around see the javadoc in the following file: opensource/java/engine/org/apache/derby/iapi/store/access/Qualifier.java the short answer is that it is a way of encoding and's and or's of qualifiers.
        Hide
        Kathey Marsden added a comment -

        Knut said:

        >Note that the class name starts with [[, which indicates that it
        >is a two-dimensional Qualifier array and not a simple Qualifier instance.

        Thanks Knut for pointing this out. I missed this entirely.

        Show
        Kathey Marsden added a comment - Knut said: >Note that the class name starts with [[, which indicates that it >is a two-dimensional Qualifier array and not a simple Qualifier instance. Thanks Knut for pointing this out. I missed this entirely.
        Hide
        Knut Anders Hatlen added a comment -

        > I would expect the error to complain about the class that
        > implements Qualifier not the interface. I will look at the
        > generated code and see if I can find anything interesting in
        > that that.

        Note that the class name starts with [[, which indicates that it
        is a two-dimensional Qualifier array and not a simple Qualifier
        instance.

        Show
        Knut Anders Hatlen added a comment - > I would expect the error to complain about the class that > implements Qualifier not the interface. I will look at the > generated code and see if I can find anything interesting in > that that. Note that the class name starts with [[, which indicates that it is a two-dimensional Qualifier array and not a simple Qualifier instance.
        Hide
        Kathey Marsden added a comment -

        With optimizer directives I changed the query to always use the constraint and then to force a table scan and neither popped the issue. I don't see what else could be done from a plan perspective for such a simple query.

        When I run the query, I find that the offending code in GenericQualifier.getOrderable():

        orderableCache = (DataValueDescriptor) (orderableGetter.invoke(activation));

        always seems to return a SQLChar from the invocation. I think it is very interesting that our error message is:
        java.lang.ClassCastException: [[Lorg.apache.derby.iapi.store.access.Qualifier; incompatible with org.apache.derby.iapi.types.DataValueDescriptor

        when derby.iapi.store.access.Qualifier is actually just an interface. I would expect the error to complain about the class that implements Qualifier not the interface. I will look at the generated code and see if I can find anything interesting in that that.

        Show
        Kathey Marsden added a comment - With optimizer directives I changed the query to always use the constraint and then to force a table scan and neither popped the issue. I don't see what else could be done from a plan perspective for such a simple query. When I run the query, I find that the offending code in GenericQualifier.getOrderable(): orderableCache = (DataValueDescriptor) (orderableGetter.invoke(activation)); always seems to return a SQLChar from the invocation. I think it is very interesting that our error message is: java.lang.ClassCastException: [[Lorg.apache.derby.iapi.store.access.Qualifier; incompatible with org.apache.derby.iapi.types.DataValueDescriptor when derby.iapi.store.access.Qualifier is actually just an interface. I would expect the error to complain about the class that implements Qualifier not the interface. I will look at the generated code and see if I can find anything interesting in that that.

          People

          • Assignee:
            Kathey Marsden
            Reporter:
            Kathey Marsden
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development