Derby
  1. Derby
  2. DERBY-1020

Network Server treats errors on cleanup of connections as an unexpected error after intentional shutdown of the database/server

    Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Minor Minor
    • Resolution: Unresolved
    • Affects Version/s: 10.1.3.1, 10.2.1.6, 10.3.1.4
    • Fix Version/s: None
    • Component/s: Network Server
    • Urgency:
      Normal

      Description

      Any exceptions that occur in the rollback and close of connections in Session.close() are treated as unexpected errors and print to the console.

      Exceptions that occur cleaning up the connection after intentional shutdown are not really unexpected.

      The console message can be disconcerting and intermittent as it depends on time. It is the root cause of DERBY-273 and I believe DERBY-803

        Issue Links

          Activity

          Hide
          Kathey Marsden added a comment -

          In a comment in DERBY-803, Deepa said:

          Scenario is: Server is shutdown. One of the threads finds that the client has disconnected. It tries to close the session but gets an exception during rollback because the shutdown has already taken place.

          Yes I think this is the case.

          In this scenario, since the client has already disconnected, can we ignore
          the exceptions when closing the session? Then, we can pass a flag to closeSession method asking to ignore exceptions if we are calling it when we receive a DisconnectException in the server. Any comments/suggestions ?

          I think that closeSession is really always an asynchronous cleanup operation and like garbage collection shouldn't ever fail. This operation performs a rollback so that it can close the connection because connection close will fail if a transaction is active. That is where the error always occurs when the database has been previously shutdown. In this case the close and cleanup should still happen normally.

          I was thinking perhaps one solution might be to add a new method to EngineConnection public void close(boolean force) which would close the connection without doing the active transaction check. That way (I think) the call would succeed regardless of the transaction or database state.

          Show
          Kathey Marsden added a comment - In a comment in DERBY-803 , Deepa said: Scenario is: Server is shutdown. One of the threads finds that the client has disconnected. It tries to close the session but gets an exception during rollback because the shutdown has already taken place. Yes I think this is the case. In this scenario, since the client has already disconnected, can we ignore the exceptions when closing the session? Then, we can pass a flag to closeSession method asking to ignore exceptions if we are calling it when we receive a DisconnectException in the server. Any comments/suggestions ? I think that closeSession is really always an asynchronous cleanup operation and like garbage collection shouldn't ever fail. This operation performs a rollback so that it can close the connection because connection close will fail if a transaction is active. That is where the error always occurs when the database has been previously shutdown. In this case the close and cleanup should still happen normally. I was thinking perhaps one solution might be to add a new method to EngineConnection public void close(boolean force) which would close the connection without doing the active transaction check. That way (I think) the call would succeed regardless of the transaction or database state.
          Hide
          Bryan Pendleton added a comment -

          I agree with the basic idea, though I'm not sure why we should need to add
          a new method and/or a new flag. It seems like it would be cleaner just to
          teach the engine not to throw an exception in this case. From my quick scan
          of the stack traces in DERBY-273, we've actually finished all the rollback
          processing at the point of the exception, and are just trying to do some
          bookkeeping to get the connection ready for the next transaction to start.

          But of course there will not be any next transaction on this connection, since
          the client is already gone and the database is shut down and we're just
          cleaning things up. So throwing an exception about what is logically part
          of the "next" transaction seems a bit over-eager to me.

          So it seems like the engine could be altered so that, rather than throwing an
          exception in this case, it could just quietly leave the connection in the state
          of "clean, but cannot be used for any future transactions".

          That way, there would be no exceptions thrown, so long as the connection
          was never used again.

          Show
          Bryan Pendleton added a comment - I agree with the basic idea, though I'm not sure why we should need to add a new method and/or a new flag. It seems like it would be cleaner just to teach the engine not to throw an exception in this case. From my quick scan of the stack traces in DERBY-273 , we've actually finished all the rollback processing at the point of the exception, and are just trying to do some bookkeeping to get the connection ready for the next transaction to start. But of course there will not be any next transaction on this connection, since the client is already gone and the database is shut down and we're just cleaning things up. So throwing an exception about what is logically part of the "next" transaction seems a bit over-eager to me. So it seems like the engine could be altered so that, rather than throwing an exception in this case, it could just quietly leave the connection in the state of "clean, but cannot be used for any future transactions". That way, there would be no exceptions thrown, so long as the connection was never used again.
          Hide
          Kathey Marsden added a comment -

          PROBLEM ANALYSIS:

          I think the source of the exception is in Database.close() in the rollback() call:

          if ((conn != null) && !conn.isClosed())
          {
          if (! forXA)

          { // The DERBY-1020 happens here on rollback if the connection is no longer active // The rollback is important in the normal case because conn.close() will fail if there is // an active transaction. conn.rollback(); }

          conn.close();
          }

          Currently any exception that occurs on rollback() or close() is ultimately caught and logged by this code in DRDAConnThread.sessionClose()
          } catch (SQLException se)

          { // If something went wrong closing down the session. // Print an error to the console and close this //thread. (6013) sendUnexpectedException(se); close(); }

          The problem is that after an intentional shutdown, the error on rollback() is not unexpected at all so it should never get to the catch block.

          Does that sound like a correct analysis?

          EXCEPTION SCENARIOS:

          If an exception happens on rollback() or close() there are basically three scenarios

          1) The connection is still active and there was some unexpected exception rolling back or closing the connection.
          This needs to be logged because it might lead to locks being held until the connection is garbage collected
          Not logging the failure would make tracking such a problem down very difficult.

          2) The connection is no longer active because of intentional shutdown. (e.g. the database has been shutdown like in 1020)
          This kind of exception, I think, can be safely ignored.

          3) The connection is no longer active because of some unexpected event like a crash. There has been some debate in the past whether this type of exception needs to be logged. I thought session level exceptions in this block of code could safely be ignored since the fact that they were session severity meant the session was shutdown. Tomohito thought it was not good to ignore them and I understand that point.

          SOLUTION OPTIONS:

          My thought was that we could remove the rollback and the associated exception by having a close() method that would force a rollback and close, something like:
          if ((conn != null) && !conn.isClosed())

          { // force the connection to rollback and close instead of throwing an error if we are in an active xact conn.forceClose(); }

          Brian suggested

          It seems like it would be cleaner just to
          teach the engine not to throw an exception in this case.

          That sounds good, but what call do we teach?

          I think Connection.rollback() still should throw an exception if the database is shutdown so we wouldn't teach rollback(). Perhaps Connection.isClosed() could return true if the database has been shutdown intentionally. That way we would never enter the code block causing the exception.

          Show
          Kathey Marsden added a comment - PROBLEM ANALYSIS: I think the source of the exception is in Database.close() in the rollback() call: if ((conn != null) && !conn.isClosed()) { if (! forXA) { // The DERBY-1020 happens here on rollback if the connection is no longer active // The rollback is important in the normal case because conn.close() will fail if there is // an active transaction. conn.rollback(); } conn.close(); } Currently any exception that occurs on rollback() or close() is ultimately caught and logged by this code in DRDAConnThread.sessionClose() } catch (SQLException se) { // If something went wrong closing down the session. // Print an error to the console and close this //thread. (6013) sendUnexpectedException(se); close(); } The problem is that after an intentional shutdown, the error on rollback() is not unexpected at all so it should never get to the catch block. Does that sound like a correct analysis? EXCEPTION SCENARIOS: If an exception happens on rollback() or close() there are basically three scenarios 1) The connection is still active and there was some unexpected exception rolling back or closing the connection. This needs to be logged because it might lead to locks being held until the connection is garbage collected Not logging the failure would make tracking such a problem down very difficult. 2) The connection is no longer active because of intentional shutdown. (e.g. the database has been shutdown like in 1020) This kind of exception, I think, can be safely ignored. 3) The connection is no longer active because of some unexpected event like a crash. There has been some debate in the past whether this type of exception needs to be logged. I thought session level exceptions in this block of code could safely be ignored since the fact that they were session severity meant the session was shutdown. Tomohito thought it was not good to ignore them and I understand that point. SOLUTION OPTIONS: My thought was that we could remove the rollback and the associated exception by having a close() method that would force a rollback and close, something like: if ((conn != null) && !conn.isClosed()) { // force the connection to rollback and close instead of throwing an error if we are in an active xact conn.forceClose(); } Brian suggested It seems like it would be cleaner just to teach the engine not to throw an exception in this case. That sounds good, but what call do we teach? I think Connection.rollback() still should throw an exception if the database is shutdown so we wouldn't teach rollback(). Perhaps Connection.isClosed() could return true if the database has been shutdown intentionally. That way we would never enter the code block causing the exception.
          Hide
          Bryan Pendleton added a comment -

          Kathey said:

          > // force the connection to rollback and close instead of throwing an error if we are in an active xact
          > conn.forceClose();

          I think that the forceClose() method that you are proposing is very similar to the idea
          I was trying to suggest about how rollback() could behave in this case.

          I thought the DERBY-273 stack traces are kind of interesting. Here's a snip from one of those traces:

          org.apache.derby.iapi.services.context.ShutdownException:
          at org.apache.derby.iapi.services.context.ContextManager.checkInterrupt(ContextManager.java:374)
          at org.apache.derby.iapi.services.context.ContextManager.popContext(ContextManager.java:152)
          at org.apache.derby.iapi.services.context.ContextImpl.popMe(ContextImpl.java:80)
          at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.resetSavepoints(GenericLanguageConnectionContext.java:1309)
          at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.doRollback(GenericLanguageConnectionContext.java:1288)

          What I find interesting about this is that at the point where doRollback() calls resetSavepoints(),
          the rollback is actually fully complete. We are at the point where the rollback code is doing:

          // reset the savepoints to the new
          // location, since any outer nesting
          // levels expet there to be a savepoint
          resetSavepoints(statementContext);

          That is, we have finished the rollback of this transaction, and now we are setting
          up savepoints in order to begin the next transaction.

          Well, there isn't going to be any next transaction. The session has disconnected,
          and we are just trying to clean it up before we discard it. We don't want the engine
          to set up a next transaction. We just want it to roll the current transaction back and then
          return to us so we can close up shop and go home.

          So it seems to me that if we just changed the very end of
          GenericLanguageConnectionContext.doRollback() so that
          the call to resetSavepoints() was conditional on whether or not the database
          had been shutdown, then rollback() would already have the semantics that you
          desire from the forceClose() method.

          In pseudo-code, something like:

          if (databaseIsOpen)
          resetSavepoints();
          else
          this.close(); // nothing more can be done with this connection

          Show
          Bryan Pendleton added a comment - Kathey said: > // force the connection to rollback and close instead of throwing an error if we are in an active xact > conn.forceClose(); I think that the forceClose() method that you are proposing is very similar to the idea I was trying to suggest about how rollback() could behave in this case. I thought the DERBY-273 stack traces are kind of interesting. Here's a snip from one of those traces: org.apache.derby.iapi.services.context.ShutdownException: at org.apache.derby.iapi.services.context.ContextManager.checkInterrupt(ContextManager.java:374) at org.apache.derby.iapi.services.context.ContextManager.popContext(ContextManager.java:152) at org.apache.derby.iapi.services.context.ContextImpl.popMe(ContextImpl.java:80) at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.resetSavepoints(GenericLanguageConnectionContext.java:1309) at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.doRollback(GenericLanguageConnectionContext.java:1288) What I find interesting about this is that at the point where doRollback() calls resetSavepoints(), the rollback is actually fully complete. We are at the point where the rollback code is doing: // reset the savepoints to the new // location, since any outer nesting // levels expet there to be a savepoint resetSavepoints(statementContext); That is, we have finished the rollback of this transaction, and now we are setting up savepoints in order to begin the next transaction . Well, there isn't going to be any next transaction. The session has disconnected, and we are just trying to clean it up before we discard it. We don't want the engine to set up a next transaction. We just want it to roll the current transaction back and then return to us so we can close up shop and go home. So it seems to me that if we just changed the very end of GenericLanguageConnectionContext.doRollback() so that the call to resetSavepoints() was conditional on whether or not the database had been shutdown, then rollback() would already have the semantics that you desire from the forceClose() method. In pseudo-code, something like: if (databaseIsOpen) resetSavepoints(); else this.close(); // nothing more can be done with this connection
          Hide
          Kathey Marsden added a comment -

          So in the general case you think that Connection.rollback() should not throw an exception if the database has been shut down? I think an error should be thrown on database access error for rollback() per:
          ttp://java.sun.com/j2se/1.5.0/docs/api/java/sql/Connection.html#rollback()

          Show
          Kathey Marsden added a comment - So in the general case you think that Connection.rollback() should not throw an exception if the database has been shut down? I think an error should be thrown on database access error for rollback() per: ttp://java.sun.com/j2se/1.5.0/docs/api/java/sql/Connection.html#rollback()
          Hide
          Bryan Pendleton added a comment -

          Yes, that was my idea, but I can see why you feel it violates the spec.

          It's fine with me if we take a more cautious approach, and use a special
          entrypoint to the engine, as you suggested earlier. I guess I was just
          trying to explore the design space a little.

          Thanks for the discussion!

          Show
          Bryan Pendleton added a comment - Yes, that was my idea, but I can see why you feel it violates the spec. It's fine with me if we take a more cautious approach, and use a special entrypoint to the engine, as you suggested earlier. I guess I was just trying to explore the design space a little. Thanks for the discussion!
          Hide
          Deepa Remesh added a comment -

          I saw this test fail on one of the test machines. From the stack trace, I see that the this intermittent error happens at different points in the rollback process not just resetSavepoints. Just something to consider when we think of a solution. Here is the stack trace:

          org.apache.derby.iapi.services.context.ShutdownException:
          at org.apache.derby.iapi.services.context.ContextManager.checkInterrupt(ContextManager.java:430)
          at org.apache.derby.iapi.services.context.ContextManager.getContext(ContextManager.java:149)
          at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.getStatementContext(GenericLanguageConnectionContext.java:2424)
          at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.doRollback(GenericLanguageConnectionContext.java:1261)
          at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.userRollback(GenericLanguageConnectionContext.java:1224)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.rollback(TransactionResourceImpl.java:242)
          at org.apache.derby.impl.jdbc.EmbedConnection.close(EmbedConnection.java:994)
          at org.apache.derby.impl.jdbc.EmbedConnection.close(EmbedConnection.java:970)
          at org.apache.derby.impl.drda.Database.close(Database.java:320)
          at org.apache.derby.impl.drda.Session.close(Session.java:110)
          at org.apache.derby.impl.drda.DRDAConnThread.closeSession(DRDAConnThread.java:7256)
          at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:256)

          Show
          Deepa Remesh added a comment - I saw this test fail on one of the test machines. From the stack trace, I see that the this intermittent error happens at different points in the rollback process not just resetSavepoints. Just something to consider when we think of a solution. Here is the stack trace: org.apache.derby.iapi.services.context.ShutdownException: at org.apache.derby.iapi.services.context.ContextManager.checkInterrupt(ContextManager.java:430) at org.apache.derby.iapi.services.context.ContextManager.getContext(ContextManager.java:149) at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.getStatementContext(GenericLanguageConnectionContext.java:2424) at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.doRollback(GenericLanguageConnectionContext.java:1261) at org.apache.derby.impl.sql.conn.GenericLanguageConnectionContext.userRollback(GenericLanguageConnectionContext.java:1224) at org.apache.derby.impl.jdbc.TransactionResourceImpl.rollback(TransactionResourceImpl.java:242) at org.apache.derby.impl.jdbc.EmbedConnection.close(EmbedConnection.java:994) at org.apache.derby.impl.jdbc.EmbedConnection.close(EmbedConnection.java:970) at org.apache.derby.impl.drda.Database.close(Database.java:320) at org.apache.derby.impl.drda.Session.close(Session.java:110) at org.apache.derby.impl.drda.DRDAConnThread.closeSession(DRDAConnThread.java:7256) at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:256)
          Hide
          Rick Hillegas added a comment -

          Triaged for 10.5.3: assigned normal urgency.

          Show
          Rick Hillegas added a comment - Triaged for 10.5.3: assigned normal urgency.

            People

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

              Dates

              • Created:
                Updated:

                Development