Derby
  1. Derby
  2. DERBY-5632

Logical deadlock happened when freezing/unfreezing the database

    Details

    • Urgency:
      Normal
    • Bug behavior facts:
      Seen in production

      Description

      Tried to make a quick database backup by freezing the database, performing a ZFS snapshot, and then unfreezing the database. The database was frozen but then a connection to the database could not be established to unfreeze the database.

      Looking at the stack trace of the network server, , I see 3 threads that are trying to process a connection request. Each of these is waiting on:

      at org.apache.derby.impl.store.access.RAMAccessManager.conglomCacheFind(Unknown Source)

      • waiting to lock <0xfffffffd3a7fcc68> (a org.apache.derby.impl.services.cache.ConcurrentCache)

      That object is owned by:

      • locked <0xfffffffd3a7fcc68> (a org.apache.derby.impl.services.cache.ConcurrentCache)
        at org.apache.derby.impl.store.access.RAMTransaction.findExistingConglomerate(Unknown Source)
        at org.apache.derby.impl.store.access.RAMTransaction.openGroupFetchScan(Unknown Source)
        at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.updateIndexStatsMinion(Unknown Source)
        at org.apache.derby.impl.services.daemon.IndexStatisticsDaemonImpl.runExplicitly(Unknown Source)
        at org.apache.derby.impl.sql.execute.AlterTableConstantAction.updateStatistics(Unknown Source)

      which itself is waiting for the object:

      at java.lang.Object.wait(Native Method)

      • waiting on <0xfffffffd3ac1d608> (a org.apache.derby.impl.store.raw.log.LogToFile)
        at java.lang.Object.wait(Object.java:485)
        at org.apache.derby.impl.store.raw.log.LogToFile.flush(Unknown Source)
      • locked <0xfffffffd3ac1d608> (a org.apache.derby.impl.store.raw.log.LogToFile)
        at org.apache.derby.impl.store.raw.log.LogToFile.flush(Unknown Source)
        at org.apache.derby.impl.store.raw.data.BaseDataFileFactory.flush(Unknown Source)

      So basically what I think is happening is that the database is frozen, the statistics are being updated on another thread which has the "org.apache.derby.impl.services.cache.ConcurrentCache" locked and then waits for the LogToFile lock and the connecting threads are waiting to lock "org.apache.derby.impl.services.cache.ConcurrentCache" to connect and these are where the database is going to be unfrozen. Not a deadlock as far as the JVM is concerned but it will never leave this state either.

      1. stack.txt
        107 kB
        Brett Bergquist
      2. experimental-v1.diff
        10 kB
        Knut Anders Hatlen
      3. experimental-v2.diff
        11 kB
        Knut Anders Hatlen

        Issue Links

          Activity

          Hide
          Brett Bergquist added a comment -

          I think the deadlocks are the same. I think we are triggering this more often. The 10.8 added the index stats daemon capability but it turned out there were some issues (that I reported). Because index statistics are important for our application and we have tables that are initially empty and quickly get filled with data, we disable the index stats daemon (or rather don't enable it) and have a background job that is running an UPDATE_STATISTICS command across all tables that appear to not have statistics. This runs every minute in the background and does not seem to have a negative effect since it is only running against those tables that don't have any index statistics.

          So there is probably a timing issue with the FREEZE and the UPDATE_STATISTICS.

          I am going to try to force a reproducible case by increasing the frequency of both of these in my utility. I will remove the actually file system backup between the freeze/unfreeze and increase the rate at with the background UPDATE_STATISTICS is being done. If I can get this to happen with a good deal of regularity, I will apply your patch and try again.

          I will post the results.

          Show
          Brett Bergquist added a comment - I think the deadlocks are the same. I think we are triggering this more often. The 10.8 added the index stats daemon capability but it turned out there were some issues (that I reported). Because index statistics are important for our application and we have tables that are initially empty and quickly get filled with data, we disable the index stats daemon (or rather don't enable it) and have a background job that is running an UPDATE_STATISTICS command across all tables that appear to not have statistics. This runs every minute in the background and does not seem to have a negative effect since it is only running against those tables that don't have any index statistics. So there is probably a timing issue with the FREEZE and the UPDATE_STATISTICS. I am going to try to force a reproducible case by increasing the frequency of both of these in my utility. I will remove the actually file system backup between the freeze/unfreeze and increase the rate at with the background UPDATE_STATISTICS is being done. If I can get this to happen with a good deal of regularity, I will apply your patch and try again. I will post the results.
          Hide
          Knut Anders Hatlen added a comment -

          I agree that only allowing unfreeze from the connection that froze the database would be limiting. Are you saying that the deadlocks involve different kinds of objects in the single-connection case than in the multiple-connection case, and that the committed fix would only have effect on the single-connection case?

          Show
          Knut Anders Hatlen added a comment - I agree that only allowing unfreeze from the connection that froze the database would be limiting. Are you saying that the deadlocks involve different kinds of objects in the single-connection case than in the multiple-connection case, and that the committed fix would only have effect on the single-connection case?
          Hide
          Brett Bergquist added a comment -

          Knut, originally this was all done using a script and IJ. The script invoked IJ to freeze the database, then did a file system backup (using bash and ZFS commands) and then invoked IJ to unfreeze the database. Mike Matrigali indicated that the expectation was that the freeze/unfreeze would be done using the same connection, so I wrote a utility in Java that would create a connection, invoke the freeze, issue a system level call to perform the file system backup, and then issue the unfreeze all in one connection. The problem still exists even doing it this way but the stack traces tare probably from the original.

          I really do have an issue with the expectation that this all be done in one connection. Even with the utility that there is a chance that the utility could fail between the time the freeze is done and the unfreeze is done. At that point Derby is done and will require to be forcefully killed.

          It would seem to me that it should always be possible to connect to the database engine. It may be that specific requests on the connection will block when the database is frozen, but the one that should not block is the unfreeze.

          I think not allowing the freeze/unfreeze from different connections is a bug.

          Show
          Brett Bergquist added a comment - Knut, originally this was all done using a script and IJ. The script invoked IJ to freeze the database, then did a file system backup (using bash and ZFS commands) and then invoked IJ to unfreeze the database. Mike Matrigali indicated that the expectation was that the freeze/unfreeze would be done using the same connection, so I wrote a utility in Java that would create a connection, invoke the freeze, issue a system level call to perform the file system backup, and then issue the unfreeze all in one connection. The problem still exists even doing it this way but the stack traces tare probably from the original. I really do have an issue with the expectation that this all be done in one connection. Even with the utility that there is a chance that the utility could fail between the time the freeze is done and the unfreeze is done. At that point Derby is done and will require to be forcefully killed. It would seem to me that it should always be possible to connect to the database engine. It may be that specific requests on the connection will block when the database is frozen, but the one that should not block is the unfreeze. I think not allowing the freeze/unfreeze from different connections is a bug.
          Hide
          Knut Anders Hatlen added a comment -

          I noticed that some of the blocked threads in the thread dump were trying to open a new connection in BrokeredConnection.isClosed(). That looks suspicious, so I have filed DERBY-6110 to investigate.

          Show
          Knut Anders Hatlen added a comment - I noticed that some of the blocked threads in the thread dump were trying to open a new connection in BrokeredConnection.isClosed(). That looks suspicious, so I have filed DERBY-6110 to investigate.
          Hide
          Knut Anders Hatlen added a comment -

          Committed revision 1456352.

          I'm marking the issue as resolved, although I can't tell if the problem is completely fixed. In any case, if there still is a deadlock after the fix, it should not involve synchronization on the conglomerate cache.

          Show
          Knut Anders Hatlen added a comment - Committed revision 1456352. I'm marking the issue as resolved, although I can't tell if the problem is completely fixed. In any case, if there still is a deadlock after the fix, it should not involve synchronization on the conglomerate cache.
          Hide
          Knut Anders Hatlen added a comment -

          I forgot to mention that all the regression tests passed with the updated patch.

          Show
          Knut Anders Hatlen added a comment - I forgot to mention that all the regression tests passed with the updated patch.
          Hide
          Knut Anders Hatlen added a comment -

          Attaching version 2 of the patch that removes the explicit synchronization on the conglomerate cache. The only difference from version 1 is the way it retrieves a handle to the current transaction from CacheableConglomerate.setIdentity(). Now it uses the nested transaction instead of the top-level user transaction if there is one.

          I wasn't quite happy with the approach used to get the current transaction (see RAMAccessManager.getCurrentTransactionContext()) as it needed to make some assumptions on how different transaction context types are stacked. I think it should do the right thing, though.

          Apart from that, I think the patch is an improvement, as it allows more concurrent access to the conglomerate cache. Whether or not it helps with the deadlock, or if it just makes it block on some other monitor, I don't know.

          Show
          Knut Anders Hatlen added a comment - Attaching version 2 of the patch that removes the explicit synchronization on the conglomerate cache. The only difference from version 1 is the way it retrieves a handle to the current transaction from CacheableConglomerate.setIdentity(). Now it uses the nested transaction instead of the top-level user transaction if there is one. I wasn't quite happy with the approach used to get the current transaction (see RAMAccessManager.getCurrentTransactionContext()) as it needed to make some assumptions on how different transaction context types are stacked. I think it should do the right thing, though. Apart from that, I think the patch is an improvement, as it allows more concurrent access to the conglomerate cache. Whether or not it helps with the deadlock, or if it just makes it block on some other monitor, I don't know.
          Hide
          Knut Anders Hatlen added a comment -

          I think there are two reasons why RAMAccessManager synchronizes on the conglomerate cache instance whenever it accesses it:

          1) Because it manually faults in missing items in the cache, and it needs to ensure that no others fault it in between its calls to findCached() and create().

          2) Because conglomCacheUpdateEntry() implements a create-or-replace operation, which is not provided by the CacheManager interface, and it needs to ensure no others add an item with the same key between findCached() and create().

          As mentioned in an earlier comment, I think (1) should be solved by implementing CacheableConglomerate.setIdentity(), so that the cache manager takes care of faulting in the conglomerate.

          (2) might be solved by adding a create-or-replace operation to CacheManager interface. However, I'm not sure it is needed. The conglomCacheUpdateEntry() method is only called once; by RAMTransaction.addColumnToConglomerate(). That method fetches a Conglomerate instance from the cache, modifies it, and reinserts it into the cache. The instance that's reinserted into the cache is the exact same instance that was fetched from the cache, so the call to conglomCacheUpdateEntry() doesn't really update the conglomerate cache, it just replaces an existing entry with itself.

          It looks to me as if the conglomCacheUpdateEntry() can be removed, and that will take care of (2).

          I created an experimental patch, attached as experimental-v1.diff. It removes conglomCacheUpdateEntry() as suggested. It also makes CacheableConglomerate implement setIdentity() so that conglomCacheFind() doesn't need to fault in conglomerates manually.

          The patch is not ready for commit, as it doesn't pass all regression tests. But it could be used for testing, if someone has a test environment where the deadlock can be reliably reproduced.

          There was only one failure in the regression tests. store/xaOffline1.sql had a diff in one of the transaction table listings, where a transaction showed up in the ACTIVE state whereas IDLE was expected.

          This probably happens because the transaction used in the CacheableConglomerate.setIdentity() method is not necessarily the same as the one previously used by RAMAccessManager.conglomCacheFind().

          The current implementation of setIdentity() in the patch just fetches the first transaction it finds on the context stack. That seems to do the trick in most cases, but it doesn't know whether conglomCacheFind() was called with a top-level transaction or a nested transaction, as setIdentity() cannot access conglomCacheFind()'s parameters. Maybe it can be solved by pushing some other context type (with a reference to the correct tx) on the context stack before accessing the conglomerate cache, and let setIdentity() check that instead?

          Show
          Knut Anders Hatlen added a comment - I think there are two reasons why RAMAccessManager synchronizes on the conglomerate cache instance whenever it accesses it: 1) Because it manually faults in missing items in the cache, and it needs to ensure that no others fault it in between its calls to findCached() and create(). 2) Because conglomCacheUpdateEntry() implements a create-or-replace operation, which is not provided by the CacheManager interface, and it needs to ensure no others add an item with the same key between findCached() and create(). As mentioned in an earlier comment, I think (1) should be solved by implementing CacheableConglomerate.setIdentity(), so that the cache manager takes care of faulting in the conglomerate. (2) might be solved by adding a create-or-replace operation to CacheManager interface. However, I'm not sure it is needed. The conglomCacheUpdateEntry() method is only called once; by RAMTransaction.addColumnToConglomerate(). That method fetches a Conglomerate instance from the cache, modifies it, and reinserts it into the cache. The instance that's reinserted into the cache is the exact same instance that was fetched from the cache, so the call to conglomCacheUpdateEntry() doesn't really update the conglomerate cache, it just replaces an existing entry with itself. It looks to me as if the conglomCacheUpdateEntry() can be removed, and that will take care of (2). I created an experimental patch, attached as experimental-v1.diff. It removes conglomCacheUpdateEntry() as suggested. It also makes CacheableConglomerate implement setIdentity() so that conglomCacheFind() doesn't need to fault in conglomerates manually. The patch is not ready for commit, as it doesn't pass all regression tests. But it could be used for testing, if someone has a test environment where the deadlock can be reliably reproduced. There was only one failure in the regression tests. store/xaOffline1.sql had a diff in one of the transaction table listings, where a transaction showed up in the ACTIVE state whereas IDLE was expected. This probably happens because the transaction used in the CacheableConglomerate.setIdentity() method is not necessarily the same as the one previously used by RAMAccessManager.conglomCacheFind(). The current implementation of setIdentity() in the patch just fetches the first transaction it finds on the context stack. That seems to do the trick in most cases, but it doesn't know whether conglomCacheFind() was called with a top-level transaction or a nested transaction, as setIdentity() cannot access conglomCacheFind()'s parameters. Maybe it can be solved by pushing some other context type (with a reference to the correct tx) on the context stack before accessing the conglomerate cache, and let setIdentity() check that instead?
          Hide
          Knut Anders Hatlen added a comment -

          I think the way the conglomerate cache is accessed breaks with the intention of how our generic cache implementation should be accessed. It should not be necessary to synchronize on the cache instance, like RAMAccessManager.conglomCacheFind() and some other callers do.

          To take conglomCacheFind() as an example, I think it ideally should have been implemented like this:

          Conglomerate conglom = null;
          CacheableConglomerate entry = (CacheableConglomerate) conglomCache.find(new Long(conglomid));
          if (entry != null)

          { conglom = entry.getConglom(); conglom_cache.release(entry); }

          return conglom;

          That is, no explicit synchronization, and let the cache implementation take care of faulting in the conglomerate if it's not in the cache.

          However, CacheableConglomerate.setIdentity(), which is where the code that faults in the conglomerate is supposed to be, is just an empty shell:

          public Cacheable setIdentity(Object key) throws StandardException
          {
          if (SanityManager.DEBUG)

          { SanityManager.THROWASSERT("not supported."); }

          return(null);
          }

          I'll have a look and see if it's possible to rewrite the code in a way so that we can remove the explicit synchronization on the conglomerate cache instance. Hopefully, that would be enough to break the deadlock.

          Show
          Knut Anders Hatlen added a comment - I think the way the conglomerate cache is accessed breaks with the intention of how our generic cache implementation should be accessed. It should not be necessary to synchronize on the cache instance, like RAMAccessManager.conglomCacheFind() and some other callers do. To take conglomCacheFind() as an example, I think it ideally should have been implemented like this: Conglomerate conglom = null; CacheableConglomerate entry = (CacheableConglomerate) conglomCache.find(new Long(conglomid)); if (entry != null) { conglom = entry.getConglom(); conglom_cache.release(entry); } return conglom; That is, no explicit synchronization, and let the cache implementation take care of faulting in the conglomerate if it's not in the cache. However, CacheableConglomerate.setIdentity(), which is where the code that faults in the conglomerate is supposed to be, is just an empty shell: public Cacheable setIdentity(Object key) throws StandardException { if (SanityManager.DEBUG) { SanityManager.THROWASSERT("not supported."); } return(null); } I'll have a look and see if it's possible to rewrite the code in a way so that we can remove the explicit synchronization on the conglomerate cache instance. Hopefully, that would be enough to break the deadlock.
          Hide
          Brett Bergquist added a comment - - edited

          This is still a major problem even when using the same connection, the database can get into a state that the freeze works, but the unfreeze locks up.

          At a customer site, this procedure is done each night to backup the database. Since the 9/1/2012, this has failed 5 times, causing the database to remain in a frozen state with no possibility of unfreezing it. When in this state, no connections to the database can be created including a connection to shut down the database. Forcefully killing the network server is the only way to recover.

          Note that there is a background job in the system that is running an UPDATE_STATISTICS every minute as in Derby 10.8.2.2, the automatic statistics update daemon has problems and cannot be used.

          Show
          Brett Bergquist added a comment - - edited This is still a major problem even when using the same connection, the database can get into a state that the freeze works, but the unfreeze locks up. At a customer site, this procedure is done each night to backup the database. Since the 9/1/2012, this has failed 5 times, causing the database to remain in a frozen state with no possibility of unfreezing it. When in this state, no connections to the database can be created including a connection to shut down the database. Forcefully killing the network server is the only way to recover. Note that there is a background job in the system that is running an UPDATE_STATISTICS every minute as in Derby 10.8.2.2, the automatic statistics update daemon has problems and cannot be used.
          Hide
          Kim Haase added a comment -

          I can open a subtask for the documentation for this issue.

          Show
          Kim Haase added a comment - I can open a subtask for the documentation for this issue.
          Hide
          Kathey Marsden added a comment -

          Changing Component to Services and Documentation from Network Server as the issue is not network server specific and at a minimum the documentation needs to be improved. It might make sense to open a subtask for the doc change if the behavior isn't changed to allow unfreeze from a separate connection.

          Show
          Kathey Marsden added a comment - Changing Component to Services and Documentation from Network Server as the issue is not network server specific and at a minimum the documentation needs to be improved. It might make sense to open a subtask for the doc change if the behavior isn't changed to allow unfreeze from a separate connection.
          Hide
          Brett Bergquist added a comment -

          I think this should be looked at and improved upon. Even following Mike's comment of trying to perform the freeze/backup/unfreeze using the same connection, I have this fail and lock out of the database occur and not be able to unfreeze. So at a minimum the documentation should be updated indicating that this might happen.

          Show
          Brett Bergquist added a comment - I think this should be looked at and improved upon. Even following Mike's comment of trying to perform the freeze/backup/unfreeze using the same connection, I have this fail and lock out of the database occur and not be able to unfreeze. So at a minimum the documentation should be updated indicating that this might happen.
          Hide
          Kathey Marsden added a comment -

          Should this be marked as an improvement?

          Show
          Kathey Marsden added a comment - Should this be marked as an improvement?
          Hide
          Rick Hillegas added a comment -

          Unchecking the 'crash' box. There is probably room for improvement here, if only in the documentation.

          Show
          Rick Hillegas added a comment - Unchecking the 'crash' box. There is probably room for improvement here, if only in the documentation.
          Hide
          Brett Bergquist added a comment -

          I don't think it is clear that one MUST use the same connection. To me that is an example of how one MIGHT do the backup. In any case, I could do it as suggested by invoking a system command from within a Java utility but my fear is as you suggested, what happens if the utility fails before performing an unfreeze? Having to kill the network server is really not a good answer.

          The 3 separate steps as I mentioned does in fact work frequently. I ran it a bunch of other times with no problems, but unfortunately (or maybe fortunately), it failed for me the very first time I tried it.

          So if one were to do it within one connection, I think that maybe if the connection is lost, then an unfreeze is done automatically to ensure not being locked out of the network server.

          Show
          Brett Bergquist added a comment - I don't think it is clear that one MUST use the same connection. To me that is an example of how one MIGHT do the backup. In any case, I could do it as suggested by invoking a system command from within a Java utility but my fear is as you suggested, what happens if the utility fails before performing an unfreeze? Having to kill the network server is really not a good answer. The 3 separate steps as I mentioned does in fact work frequently. I ran it a bunch of other times with no problems, but unfortunately (or maybe fortunately), it failed for me the very first time I tried it. So if one were to do it within one connection, I think that maybe if the connection is lost, then an unfreeze is done automatically to ensure not being locked out of the network server.
          Hide
          Mike Matrigali added a comment -

          Here is the documentation for using freeze/unfreeze to do a backup. The expectation is that the freeze and unfreeze comes
          from the same connection (or at least that is likely what is tested in derby).
          http://db.apache.org/derby/docs/dev/adminguide/cadminhubbkup75469.html

          I don't remember but think it might be likely that future connection requests are stalled while a database is frozen, as part of work
          necessary to keep a database in an ok state for a user backup routine to be called. Logically you just need to stop writing transactions
          but the implementation may just of have stall all connections.

          Obviously this does not work well for the 3 separate script steps you describe, but would be good to know if your use case works for
          the intended use of freeze/unfreeze. And even if derby only supports same connection freeze
          and unfreeze, we should understand what is expected if the connection executing the freeze fails or exits before doing unfreeze.

          Show
          Mike Matrigali added a comment - Here is the documentation for using freeze/unfreeze to do a backup. The expectation is that the freeze and unfreeze comes from the same connection (or at least that is likely what is tested in derby). http://db.apache.org/derby/docs/dev/adminguide/cadminhubbkup75469.html I don't remember but think it might be likely that future connection requests are stalled while a database is frozen, as part of work necessary to keep a database in an ok state for a user backup routine to be called. Logically you just need to stop writing transactions but the implementation may just of have stall all connections. Obviously this does not work well for the 3 separate script steps you describe, but would be good to know if your use case works for the intended use of freeze/unfreeze. And even if derby only supports same connection freeze and unfreeze, we should understand what is expected if the connection executing the freeze fails or exits before doing unfreeze.
          Hide
          Brett Bergquist added a comment -

          Network server threads stack dump

          Show
          Brett Bergquist added a comment - Network server threads stack dump

            People

            • Assignee:
              Knut Anders Hatlen
              Reporter:
              Brett Bergquist
            • Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development