Derby
  1. Derby
  2. DERBY-4343

ASSERT FAILED calling setTransactionIsolation checking isolation_ == level on pooled connection

    Details

    • Issue & fix info:
      High Value Fix, Newcomer, Patch Available, Repro attached

      Description

      For DERBY-4314, I thought I would do a little testing to understand the server round trips in various scenarios for pooled connections. So I wrote the small attached program ConnReuse.java and hit this assertion in client:

      Exception in thread "main" org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED
      at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:98)
      at org.apache.derby.client.am.Connection.setTransactionIsolationX(Connection.java:987)
      at org.apache.derby.client.am.Connection.setTransactionIsolation(Connection.java:915)
      at org.apache.derby.client.am.LogicalConnection.setTransactionIsolation(LogicalConnection.java:253)
      at TestConnReuse.main(TestConnReuse.java:32)
      ---------------

      To run the program on trunk:
      java org.apache.derby.drda.NetworkServerControl start
      java TestConnReuse.

      This needs more investigation, but I thought I would go ahead and log the bug. I tried this only on trunk. I have not yet

      • Tried it on the branches.
      • Tried it with Lily's DERBY-4314 patch.
      • Tried it with embedded.
      • Tried actually doing something with the prior logical connection which might be related.
      1. DERBY-4343-4-trunk.diff
        3 kB
        Lily Wei
      2. DERBY-4343-3-testcase.diff
        3 kB
        Lily Wei
      3. DERBY-4343-2-testcase.diff
        3 kB
        Lily Wei
      4. DERBY-4343-testcase.diff
        3 kB
        Lily Wei
      5. TestConnReuse.java
        1 kB
        Lily Wei
      6. _cpds_0
        54 kB
        Lily Wei
      7. TestConnReuse.java
        1 kB
        Kathey Marsden

        Issue Links

          Activity

          Hide
          Kathey Marsden added a comment -

          Once the test case is working it would be interesting to try this with DERBY-4314 with drda tracing on to better understand the server round trips with that change.

          Show
          Kathey Marsden added a comment - Once the test case is working it would be interesting to try this with DERBY-4314 with drda tracing on to better understand the server round trips with that change.
          Hide
          Lily Wei added a comment -

          I tried in on 10.5 branches. The test ASSERT too.

          I tried it with my DERBY-4314 patch. The test passed. I trun the trace on with -Dderby.drda.traceAll=true. However, nothing interesting write to derby.log.

          Show
          Lily Wei added a comment - I tried in on 10.5 branches. The test ASSERT too. I tried it with my DERBY-4314 patch. The test passed. I trun the trace on with -Dderby.drda.traceAll=true. However, nothing interesting write to derby.log.
          Hide
          Kristian Waagan added a comment -

          I believe I understand why the assert happens.
          When obtaining the pooled connection for the third time, the variable isolation_ is reset by the following code in Connection.completeReset:
          if (closeStatementsOnClose) {
          // NOTE: This is to match previous behavior.
          // Investigate and check if it is really necessary.
          this.isolation_ = TRANSACTION_UNKNOWN;
          java.util.Set keySet = openStatements_.keySet();
          for (java.util.Iterator i = keySet.iterator(); i.hasNext()

          { Object o = i.next(); ((Statement) o).reset(closeStatementsOnClose); }

          } else

          { When setTransactionIsolation is called, and actually executed, the server doesn't send any piggybacked update because the level hasn't changed. This means the isolation_ will remain as UNKNOWN until getTransactionIsolation is called or a different statement causing a change of the isolation level is executed. DERBY-4314 causes the assert to never be reached by (in this case) querying the server about the isolation level and then short-circuiting setTransactionIsolation: + // Derby-4314 fix, the client driver should acted like embedded + if (level == getTransactionIsolationX()) + return; For completeness, removing the return in this case would also make the assert pass, since getTransactionIsolationX would have updated the value of isolation_. My take on this assert is that it is doesn't have any consequences "in the real world". Next time the user asks for the isolation level, it will be fetched from the server and a correct value will be returned. I'm +1 for patch DERBY-4314-5.diff, but I'm not yet confident resetting the value to READ_COMMITTED is the best solution (as of today, I think it is a correct change though). The patch won't improve the performance, it will just move the round-trip. In some cases I believe it will make it worse for the initial setTransactionIsolation call, depending on whether the value being set is READ_COMMITTED or not. If it is, we still get one round-trip (check + short-circuit), but if it isn't we get two (check + change). Note that the situation is slightly different when the client side JDBC statement cache is enabled. This means that for better performance, we need additional changes. Not thinking ahead, the simplest change would be to assume that the default isolation level will be READ_COMMITTED for ever. If this turns out to be false in the future, we may get out of it using version checks. A better, but more demanding solution, would be to obtain the default isolation level at initial connection time, for instance using the existing piggybacking feature. This still requires a version check in the server, but gives us more flexibility [1]. On top of this we have the XA scenario, which I understand requires some extra care to avoid returning stale/incorrect values. Thoughts? [1] I'm thinking about optimizing this situation in Connection.completeReset: }

          else {
          // Must reset transaction isolation level if it has been changed.
          if (isolation_ != Connection.TRANSACTION_READ_COMMITTED)

          { // This might not fare well with connection pools, if it has // been configured to deliver connection with a different // isolation level, i.e. it has to set the isolation level again // when it returns connection to client. // TODO: Investigate optimization options. setTransactionIsolationX(Connection.TRANSACTION_READ_COMMITTED); }

          With the described approach, the default level could be configured in the connection url with an attribute. I do not know if this is allowed by the relevant standards, or if it is something we ever want to do.

          Show
          Kristian Waagan added a comment - I believe I understand why the assert happens. When obtaining the pooled connection for the third time, the variable isolation_ is reset by the following code in Connection.completeReset: if (closeStatementsOnClose) { // NOTE: This is to match previous behavior. // Investigate and check if it is really necessary. this.isolation_ = TRANSACTION_UNKNOWN; java.util.Set keySet = openStatements_.keySet(); for (java.util.Iterator i = keySet.iterator(); i.hasNext() { Object o = i.next(); ((Statement) o).reset(closeStatementsOnClose); } } else { When setTransactionIsolation is called, and actually executed, the server doesn't send any piggybacked update because the level hasn't changed. This means the isolation_ will remain as UNKNOWN until getTransactionIsolation is called or a different statement causing a change of the isolation level is executed. DERBY-4314 causes the assert to never be reached by (in this case) querying the server about the isolation level and then short-circuiting setTransactionIsolation: + // Derby-4314 fix, the client driver should acted like embedded + if (level == getTransactionIsolationX()) + return; For completeness, removing the return in this case would also make the assert pass, since getTransactionIsolationX would have updated the value of isolation_. My take on this assert is that it is doesn't have any consequences "in the real world". Next time the user asks for the isolation level, it will be fetched from the server and a correct value will be returned. I'm +1 for patch DERBY-4314-5.diff, but I'm not yet confident resetting the value to READ_COMMITTED is the best solution (as of today, I think it is a correct change though). The patch won't improve the performance, it will just move the round-trip. In some cases I believe it will make it worse for the initial setTransactionIsolation call, depending on whether the value being set is READ_COMMITTED or not. If it is, we still get one round-trip (check + short-circuit), but if it isn't we get two (check + change). Note that the situation is slightly different when the client side JDBC statement cache is enabled. This means that for better performance, we need additional changes. Not thinking ahead, the simplest change would be to assume that the default isolation level will be READ_COMMITTED for ever. If this turns out to be false in the future, we may get out of it using version checks. A better, but more demanding solution, would be to obtain the default isolation level at initial connection time, for instance using the existing piggybacking feature. This still requires a version check in the server, but gives us more flexibility [1]. On top of this we have the XA scenario, which I understand requires some extra care to avoid returning stale/incorrect values. Thoughts? [1] I'm thinking about optimizing this situation in Connection.completeReset: } else { // Must reset transaction isolation level if it has been changed. if (isolation_ != Connection.TRANSACTION_READ_COMMITTED) { // This might not fare well with connection pools, if it has // been configured to deliver connection with a different // isolation level, i.e. it has to set the isolation level again // when it returns connection to client. // TODO: Investigate optimization options. setTransactionIsolationX(Connection.TRANSACTION_READ_COMMITTED); } With the described approach, the default level could be configured in the connection url with an attribute. I do not know if this is allowed by the relevant standards, or if it is something we ever want to do.
          Hide
          Kathey Marsden added a comment -

          Hi Lily,
          You should specify -Dderby.drda.traceAll=true on the server startup or in derby.properties, not on the client invocation and then will see the trace in a file called Server1.trace. Alternately, you can use the client side tracing. See
          http://wiki.apache.org/db-derby/ProtocolDebuggingTips
          for more tracing information.

          Thanks Kristian for the analysis. I am changing to minor since you see no impact with insane builds. The rest I will try to digest later,

          Show
          Kathey Marsden added a comment - Hi Lily, You should specify -Dderby.drda.traceAll=true on the server startup or in derby.properties, not on the client invocation and then will see the trace in a file called Server1.trace. Alternately, you can use the client side tracing. See http://wiki.apache.org/db-derby/ProtocolDebuggingTips for more tracing information. Thanks Kristian for the analysis. I am changing to minor since you see no impact with insane builds. The rest I will try to digest later,
          Hide
          Lily Wei added a comment -

          Thank to Kathey, I turn the tracing with ClientConnectionPoolDataSource.setTraceDirectory("client"); And, the trace file is attached. The test first call setTransactionIsolation with TRANSACTION_READ_COMMITTED. On second connection, the test call setTransactionIsolation with TRANSACTION_READ_COMMITTED. On the third connection, test call setTransactionIsolation with TRANSACTION_READ_UNCOMMITTED.

          From tracing, I see the test go through setTransactionIsolation(2) call and then go to getTransactionIsolationX. On second connection, the test call setTrasactionIsolation(2) and then go to getTransactionIsolationX. On the third connection, the test call setTransactionIsolation(1) and go to getTransactionIsolationX().

          This is done with DERBY-4314 patch.

          Thank Kristian for your detail analysis. I believe we should chage isolation = TRANSACTION_READ_COMMITTED with addtional change.

          Show
          Lily Wei added a comment - Thank to Kathey, I turn the tracing with ClientConnectionPoolDataSource.setTraceDirectory("client"); And, the trace file is attached. The test first call setTransactionIsolation with TRANSACTION_READ_COMMITTED. On second connection, the test call setTransactionIsolation with TRANSACTION_READ_COMMITTED. On the third connection, test call setTransactionIsolation with TRANSACTION_READ_UNCOMMITTED. From tracing, I see the test go through setTransactionIsolation(2) call and then go to getTransactionIsolationX. On second connection, the test call setTrasactionIsolation(2) and then go to getTransactionIsolationX. On the third connection, the test call setTransactionIsolation(1) and go to getTransactionIsolationX(). This is done with DERBY-4314 patch. Thank Kristian for your detail analysis. I believe we should chage isolation = TRANSACTION_READ_COMMITTED with addtional change.
          Hide
          Lily Wei added a comment -

          With fix for DERBY-4314, this issue has been resolved also.
          I am adding test case with four connections on ClientConnectionPoolDataSource to J2EEDataSource Test test. From testing structure point of view, it is easier to add to J2EEDataSourceTest instead of setTransactionIsolationTest.
          The case where we execute a statement in local transaction within global transaction is also added. Thx, Lily

          Show
          Lily Wei added a comment - With fix for DERBY-4314 , this issue has been resolved also. I am adding test case with four connections on ClientConnectionPoolDataSource to J2EEDataSource Test test. From testing structure point of view, it is easier to add to J2EEDataSourceTest instead of setTransactionIsolationTest. The case where we execute a statement in local transaction within global transaction is also added. Thx, Lily
          Hide
          Lily Wei added a comment -

          Change to use ConnectionPoolDataSource so we add embedded testing and jdbc4 datasource testing.

          Show
          Lily Wei added a comment - Change to use ConnectionPoolDataSource so we add embedded testing and jdbc4 datasource testing.
          Hide
          Kathey Marsden added a comment -

          Lily, thank you for the patch, but I tried it on 10.5 and it passes there. Do you know why?

          Show
          Kathey Marsden added a comment - Lily, thank you for the patch, but I tried it on 10.5 and it passes there. Do you know why?
          Hide
          Lily Wei added a comment -

          Thank you, Kathey. The reason they are passing is because the isolation level I set with each connection is different than the repro case in TestConnReuse. I changed the test case so it failed n 10.5 for me now.

          Show
          Lily Wei added a comment - Thank you, Kathey. The reason they are passing is because the isolation level I set with each connection is different than the repro case in TestConnReuse. I changed the test case so it failed n 10.5 for me now.
          Hide
          Lily Wei added a comment -

          DERBY-4343-3-testcase.diff is with first connection set to TRANSACTION.READ_COMMITTED and second connection just open and close connection. The third connection is set to TRANSACTION.READ_COMMITTED and the fourth connection set to TRANSACTION.READ_UNCOMMITTED on 10.5 branch.
          DERBY-4343-4-trunk.diff is the same change as DERBY-4343-3-testcase but for trunk branch. I verified the test fail with 10.5 but pass with trunk branch.

          Show
          Lily Wei added a comment - DERBY-4343 -3-testcase.diff is with first connection set to TRANSACTION.READ_COMMITTED and second connection just open and close connection. The third connection is set to TRANSACTION.READ_COMMITTED and the fourth connection set to TRANSACTION.READ_UNCOMMITTED on 10.5 branch. DERBY-4343 -4-trunk.diff is the same change as DERBY-4343 -3-testcase but for trunk branch. I verified the test fail with 10.5 but pass with trunk branch.
          Hide
          Lily Wei added a comment -

          Thanks to Kathey for all the help and check-in the test. This issue should be closed.

          Show
          Lily Wei added a comment - Thanks to Kathey for all the help and check-in the test. This issue should be closed.
          Hide
          Lily Wei added a comment -

          Reopen to 10.5 back port

          Show
          Lily Wei added a comment - Reopen to 10.5 back port
          Hide
          Mike Matrigali added a comment -

          this looks like just a test for a change that is not being backported, so probably should not be backported.

          Show
          Mike Matrigali added a comment - this looks like just a test for a change that is not being backported, so probably should not be backported.
          Hide
          Kathey Marsden added a comment -

          That makes sense. The real changes was in DERBY-4314 which might cause an issue if someone is depending on setTransactionIsolation to commit. So this one should come of the list.

          Show
          Kathey Marsden added a comment - That makes sense. The real changes was in DERBY-4314 which might cause an issue if someone is depending on setTransactionIsolation to commit. So this one should come of the list.
          Hide
          Lily Wei added a comment -

          That make sense to me too. We should not back port this to 10.5

          Show
          Lily Wei added a comment - That make sense to me too. We should not back port this to 10.5
          Hide
          Lily Wei added a comment -

          Does not need to back port to 10.5

          Show
          Lily Wei added a comment - Does not need to back port to 10.5
          Hide
          Kathey Marsden added a comment -

          Reopen for backport

          Show
          Kathey Marsden added a comment - Reopen for backport
          Hide
          Myrna van Lunteren added a comment -

          Looks like this was reopened for backport by mistake and left open as a result.

          Show
          Myrna van Lunteren added a comment - Looks like this was reopened for backport by mistake and left open as a result.

            People

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

              Dates

              • Created:
                Updated:
                Resolved:

                Development