Issue Details (XML | Word | Printable)

Key: JDBC-472
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Major Major
Assignee: Mark Rotteveel
Reporter: Mirko Vetrano
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
Jaybird JCA/JDBC Driver

java.sql.SQLNonTransientException: Unsupported or unexpected operation code 0 in processOperation [SQLState:08000, ISC error code:337248276]

Created: 30/Dec/16 08:45 AM   Updated: 05/Mar/17 12:59 PM
Component/s: JDBC driver
Affects Version/s: Jaybird 3.0.0-beta-2
Fix Version/s: Jaybird 3.0.0-beta-3, Jaybird 3.0.0

Environment: CentOS 7, jdk1.8.0_112, Tomcat 9_M11


 Description  « Hide
When executing a preparedStatement about a stored procedure invoked like "EXECUTE PROCEDURE NAME_OF_THE_STORED(?,?)" I obtain this kind of exception:

java.sql.SQLNonTransientException: Unsupported or unexpected operation code 0 in processOperation [SQLState:08000, ISC error code:337248276]
at org.firebirdsql.gds.ng.FbExceptionBuilder$Type$4.createSQLException(FbExceptionBuilder.java:528)
at org.firebirdsql.gds.ng.FbExceptionBuilder.toFlatSQLException(FbExceptionBuilder.java:299)
at org.firebirdsql.gds.ng.wire.AbstractWireOperations.processOperation(AbstractWireOperations.java:208)
at org.firebirdsql.gds.ng.wire.AbstractWireOperations.readSingleResponse(AbstractWireOperations.java:166)
at org.firebirdsql.gds.ng.wire.AbstractWireOperations.readResponse(AbstractWireOperations.java:150)
at org.firebirdsql.gds.ng.wire.AbstractWireOperations.readGenericResponse(AbstractWireOperations.java:252)
at org.firebirdsql.gds.ng.wire.AbstractFbWireDatabase.readGenericResponse(AbstractFbWireDatabase.java:173)
at org.firebirdsql.gds.ng.wire.version12.V12Statement.execute(V12Statement.java:95)
at org.firebirdsql.jdbc.AbstractPreparedStatement.internalExecute(AbstractPreparedStatement.java:787)
at org.firebirdsql.jdbc.AbstractPreparedStatement.executeUpdate(AbstractPreparedStatement.java:210)
at services.DataService.executeQueryOperationDescriptor(DataService.java:9433)
at services.DataService.storedProcedure_NAME_OF_THE_STORED(DataService.java:7204)

This happens with all the stored procedures that return nothing (no return type of any kind). I've tried with executeUpdate and execute from the jaybird3.0-beta2 driver without success.

Thanks for your help about that. Have a nice day and happy new year.

 All   Comments   Change History   Subversion Commits      Sort Order: Ascending order - Click to sort in descending order
Mark Rotteveel added a comment - 31/Dec/16 09:14 AM
I can't reproduce the problem you describe. Can you provide me with the minimal DDL and Java code to reproduce this. I'd also like to know which Firebird version (full version number) you are using.

Mirko Vetrano added a comment - 02/Jan/17 07:05 PM
I'm using Firebird latest stable version 3.0.1.32609-0 (linux 64 bit version). Today I notice, reading an old version of the documentation, that selectable procedure "might produce strange results" if used with EXECUTE PROCEDURE (this is not my case), but a few pages after I found an example about a non-selectable procedure with a PreparedStatement and executeQuery (so similar to my case). I'm trying this solution and seems to work.
This is the url to the guide: https://www.firebirdsql.org/file/documentation/drivers_documentation/Jaybird_2_1_JDBC_driver_manual.pdf
Pages 45 and 47.
This is strange cause executeUpdate works fine nine times on ten, and the javadoc description speaks about INSERT, UPDATE, DELETE and operations without a return.
I hope to be helpful to people who make my same misunderstanding.
If I made mistakes please correct me, I need to know if this is the correct way.
Thank you for your patience

Mark Rotteveel added a comment - 03/Jan/17 08:05 AM
If your stored procedure doesn't have values to return, then it shouldn't be created as a selectable (ie: it shouldn't have any SUSPEND statement in it), however the "strange results" in "however this call might produce strange results" should read "unexpected results", as in if you use execute procedure with a selectable procedure, it will only do the work up to the first suspend and then exit, and that might be something you don't expect.

However it sounds like an actual bug in Jaybird (or in Firebird), as the exception indicates that Firebird is sending data not expected by Jaybird, so I would really appreciate it if you could help me identify the problem with a sample program (both database and Java), and some instructions as to how to reproduce it.

Note that executing a stored procedure without any return values should produce an exception when using executeQuery, so if that works for you, then that is also a bug in Jaybird. The methods executeUpdate or execute are the right methods to execute the stored procedure based on your description.

Mirko Vetrano added a comment - 10/Jan/17 10:56 AM
Example of Stored Procedure:

CREATE OR ALTER PROCEDURE EXAMPLE_PROCEDURE(
    EX_ID id)
AS
DECLARE VARIABLE EX_BL BOOL;
  /* ... (declaring other variables) */
BEGIN

  /*
  RECOVERING INFORMATION
  */
  SELECT
    /* SELECTING SOME FIELDS */
    COALESCE(EXAMPLE_DATE - 1, CURRENT_DATE)
  FROM
    EXAMPLE_TABLE
  WHERE
    ID = :EX_ID
  INTO
    /* SAME AS TABLE FIELD NAMES */

  IF (EX_BL) THEN
    DELETE FROM ANOTHER_EXAMPLE_TABLE WHERE EX_ID = :EX_ID;
  ELSE
  BEGIN
    /*
    ANOTHER SELECT
    */
    SELECT FIRST 1
      /* FIELDS */
    FROM
      ANOTHER_EXAMPLE_TABLE
    WHERE
      EX_ID = :EX_ID
    ORDER BY
      EXAMPLE_DATE_2
    INTO
     /* ALIASES */

    IF (/* CONDITION */) THEN
    BEGIN
      EXAMPLE_DATE = EXAMPLE_DATE_2;
      WHILE (/* CONDITION */) DO
      BEGIN
        INSERT INTO EXAMPLE_TABLE_2 (
          /* FIELDS */)
        VALUES (
          :EX_ID,
         /* OTHER VALUES */);
        EXAMPLE_DATE = EXAMPLE_DATE + 1;
      END
    END

    SELECT FIRST 1
      /* FIELDS */
    FROM
      EXAMPLE_TABLE_2
    WHERE
      EX_ID = :EX_ID
    ORDER BY
      EXAMPLE_DATE_2 DESC
    INTO
     /* ALIASES */;

    IF (/* CONDITION */) THEN
    BEGIN
      EXAMPLE_DATE = EXAMPLE_DATE_2;
      WHILE (/* CONDITION */) DO
      BEGIN
        INSERT INTO EXAMPLE_TABLE_2 (
          EX_ID,
         /* FIELDS */)
        VALUES (
          :EX_ID,
          /* VALUES */);
        EXAMPLE_DATE = EXAMPLE_DATE + 1;
      END
    END

    DELETE FROM
      EXAMPLE_TABLE_2
    WHERE
      (EX_ID = :EX_ID) AND
      ((EXAMPLE_DATA < :/* VALUE */) OR (EXAMPLE_DATA_2 > :/* VALUE */));
  END

END

-----------------------------------------------
I cannot be more specific than this. The code is tested and working on Firebird 3.0.1.32609-0 (linux 64 bit version).
On Java code I create a PreparedStatement:
"EXECUTE PROCEDURE EXAMPLE_PROCEDURE(?)"
passing as argument a Long
ps.setLong(id); // The id is a Long object (Wrapper Class)
I'm using a connection of type READ_COMMITTED, set on WRITE (not OnlyRead), at the end of the procedure I call
connection.commit(); // cause of connection.setAutoCommit(false); previously
The stored procedure works on data but Jaybird shows that kind of Exception.

I don't know if this can be caused by this Exception but I also have these Warnings after the exception occurs (few minutes later):
[http-nio-8080-exec-5] org.firebirdsql.logging.JulLogger.warn Commit not completed, state was COMMITTING
 java.lang.RuntimeException: Commit not completed
at org.firebirdsql.gds.ng.wire.version10.V10Transaction.commit(V10Transaction.java:94)
at org.firebirdsql.jca.FBManagedConnection.internalCommit(FBManagedConnection.java:648)
at org.firebirdsql.jca.FBLocalTransaction.internalCommit(FBLocalTransaction.java:193)
at org.firebirdsql.jca.FBLocalTransaction.commit(FBLocalTransaction.java:167)
at org.firebirdsql.jdbc.InternalTransactionCoordinator$AbstractTransactionCoordinator.internalCommit(InternalTransactionCoordinator.java:258)
at org.firebirdsql.jdbc.InternalTransactionCoordinator$LocalTransactionCoordinator.commit(InternalTransactionCoordinator.java:441)
at org.firebirdsql.jdbc.InternalTransactionCoordinator.commit(InternalTransactionCoordinator.java:160)
at org.firebirdsql.jdbc.FBConnection.commit(FBConnection.java:465)
at services.DataService.executeQueryOperationDescriptor(DataService.java:10798)
at services.DataService.storedProcedure_EXAMPLE_STORED(DataService.java:8143)

and sequently

[http-nio-8080-exec-5] org.firebirdsql.logging.JulLogger.warn Rollback not completed, state was ROLLING_BACK
 java.lang.RuntimeException: Rollback not completed
at org.firebirdsql.gds.ng.wire.version10.V10Transaction.rollback(V10Transaction.java:114)
at org.firebirdsql.jca.FBManagedConnection.internalCommit(FBManagedConnection.java:652)
at org.firebirdsql.jca.FBLocalTransaction.internalCommit(FBLocalTransaction.java:193)
at org.firebirdsql.jca.FBLocalTransaction.commit(FBLocalTransaction.java:167)
at org.firebirdsql.jdbc.InternalTransactionCoordinator$AbstractTransactionCoordinator.internalCommit(InternalTransactionCoordinator.java:258)
at org.firebirdsql.jdbc.InternalTransactionCoordinator$LocalTransactionCoordinator.commit(InternalTransactionCoordinator.java:441)
at org.firebirdsql.jdbc.InternalTransactionCoordinator.commit(InternalTransactionCoordinator.java:160)
at org.firebirdsql.jdbc.FBConnection.commit(FBConnection.java:465)
at services.DataService.executeQueryOperationDescriptor(DataService.java:10798)
at services.DataService.storedProcedure_POPOLA_RSA_ITA_LOG_STANZE(DataService.java:8143)

This can be caused by the commit() fault and the subsequently automatic rollback().

Mark Rotteveel added a comment - 10/Jan/17 12:51 PM
Thanks for the additional information; I will see if I can reproduce it with this information.

Mark Rotteveel added a comment - 11/Jan/17 02:29 PM
I have tried to create a functioning procedure based on your example code, but I can't trigger the exception that way. There may be some extra conditions or behavior involved that I'm just not able to trigger this way. It would be really helpful to have an executable example that demonstrates the problem repeatably.

Have you tried recreating the procedure? I have heard rumors that it may be necessary to recreate your stored procedures when migrating from Firebird 2.5 and earlier to Firebird 3.

The failures to commit and rollback are probably subsequent failures because of the inconsistent state of the connection stream (Jaybird isn't reading what it thinks it is reading).

Mark Rotteveel added a comment - 11/Jan/17 03:12 PM
Reviewing the execute code, I found a slightly different implementation of executing stored procedures compared to Jaybird 2.2 which could explain the difference in behavior (although right now I don't understand why I can't trigger the problem).

I am doing some tests now, would you be willing to try and test this with a snapshot version?

Mirko Vetrano added a comment - 11/Jan/17 03:44 PM
OK. I need a week (I hope less, but there is a lot of work now) to give you back a feedback. I cannot create a working executable cause of copyright issue with my company (I'm only an employee and cannot divulgate nothing).

Mark Rotteveel added a comment - 11/Jan/17 04:06 PM
Thanks for your time on this. I have made a snapshot build you can use for testing

Jaybird-3.0.0-SNAPSHOT-JDK_1.8: https://www.dropbox.com/s/3qy5m0qyoy71d62/Jaybird-3.0.0-SNAPSHOT-JDK_1.8.zip?dl=0

or if you need Java 7:
Jaybird-3.0.0-SNAPSHOT-JDK_1.7: https://www.dropbox.com/s/lhzh0qt5n60i3j0/Jaybird-3.0.0-SNAPSHOT-JDK_1.7.zip?dl=0

If this doesn't fix the problem, I will really need to have something that can reproduce this with some consistency.

Mark Rotteveel added a comment - 12/Jan/17 03:15 PM
I made some more changes based on a wild guess of what the problem could be, the above links have been updated with a new version.

Mirko Vetrano added a comment - 24/Jan/17 10:54 AM
After testing for a week, I can write that the error is not more logged on the tomcat log file. The SNAPSHOT version works very good.
Thanks a lot for your support.

Mark Rotteveel added a comment - 27/Jan/17 01:12 PM
Mirko, thank you very much for testing this and confirming it now works.