[#962] Flag an admin action when a bounded storage write gives up on a configuration change

Storage.write() no longer retries until it succeeds: JDBCStorage.write() has long been bounded by
a number of attempts and a time window, and PDBStorage.write() is bounded too since #937. Once the
bound is spent, write() throws instead of replaying.

Four configuration change paths of the pluggable backends change in-memory state around such a
write, and none of them told the operator when the memory and the storage stopped agreeing: each
set the server error result code and handed back a bare single line stack trace, with no message
id to search the error log for and nothing said about what to do next.

- AttributeIndexCfgManager.applyConfigurationDelete takes the index out of attrIndexMap and
  attrCryptoMap before the write, so a write which gives up leaves the trees in the storage while
  the configuration entry naming them is already gone.
- VLVIndexCfgManager.applyConfigurationDelete does the same for a VLV index, whose data is held by
  two trees, the index and the counter which goes with it.
- AttributeIndex.applyConfigurationChange applies the change with three writes: giving up on the
  second leaves the trees of the removed indexes behind, and giving up on the third leaves the
  entry limit the new configuration declares unapplied to the indexes which stay.
- EntryContainer.applyConfigurationChange hands the entries and every index of the backend the
  parameters to encode with from now on, and giving up between the two leaves them encoded under
  settings which no longer agree.

All four now report a message of their own - ERR_CONFIG_INDEX_DELETE_FAILED,
ERR_CONFIG_VLV_INDEX_DELETE_FAILED, ERR_CONFIG_INDEX_CHANGE_FAILED and
ERR_CONFIG_BACKEND_DATA_CHANGE_FAILED - which names what diverged and what has to be done about it,
keeps the stack trace as its trailing cause, sets adminActionRequired, and is logged as well as
returned: the divergence outlives the session which asked for the change.

The order of the two deletions is deliberately left alone: deleting inside the write would let a
replayed attempt find nothing to delete and commit an empty transaction, reporting success for
work it did not do.

AttributeIndex.applyConfigurationChange now publishes each part of the change after the write which
applied that part, rather than all of it between the first write and the second: the map of indexes
and the indexing options once the deletion has committed, still inside the entry container lock,
and the configuration once the update has committed.

EntryContainer.applyConfigurationChange no longer opens a transaction. Its body has performed no
transactional work since what it wrapped was removed - 7713117 added the wrapper around the
opening of the subordinate indexes and their entry limits, and 9f0904f (OPENDJ-1725) took that
work out of it, leaving id2entry.setDataConfig and the assignment of config behind - so what was
left was a transaction a bounded storage could give up on, in the middle of a sequence no rollback
can undo. The single step which
can fail, newDataConfig(cfg), now runs before the first mutation. The entry container lock stays:
publishing to the other threads was always its doing and never the transaction's.

ConfigChangeGivesUpTest covers the four paths through a backend whose storage gives up on a chosen
write, and pins what the messages claim, including the adoption of the trees left behind that
ERR_CONFIG_INDEX_DELETE_FAILED describes (#990).

Author: maximthomas

opendj-server-legacy/src/main/java/org/opends/server/backends/pdb/PDBStorage.java

@@ -712,8 +712,8 @@ public void write(WriteOperation operation) throws Exception
         if (capSpent || (attempt > 1 && now - giveUpAt >= 0))
         {
           final long elapsedMs = TimeUnit.NANOSECONDS.toMillis(now - startedAt);
-          //which of the two bounds was spent, so that the config change paths - which report this as a bare stack
-          //trace with no message id - say whether raising the attempts or the window is what would have helped
+          //which of the two bounds was spent, so that the config change paths - which report this as the trailing
+          //cause of a message of their own - say whether raising the attempts or the window is what would have helped
           final String boundSpent = capSpent ? "attempt cap" : "retry window";
           final StorageRuntimeException spent = new StorageRuntimeException(
               "pdb: backend '" + config.getBackendId() + "' did not apply the transaction after " + attempt

opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/AttributeIndex.java

@@ -973,10 +973,6 @@ public void run(WriteableTransaction txn) throws Exception
         ccr.addMessage(NOTE_INDEX_ADD_REQUIRES_REBUILD.get(addedIndex));
       }
 
-      config = newConfiguration;
-      indexingOptions = newIndexingOptions;
-      indexIdToIndexes = Collections.unmodifiableMap(newIndexIdToIndexes);
-
       // We get exclusive lock to ensure that no query is actually using the indexes that will be deleted.
       entryContainer.lock();
       try
@@ -992,6 +988,17 @@ public void run(WriteableTransaction txn) throws Exception
             }
           }
         });
+        // Published once the deletion has committed, not before it: a write the storage gives up on
+        // leaves the trees of the removed indexes behind, and a map which no longer names them is a
+        // map through which nothing maintains them and nothing deletes them. The lock has drained
+        // every operation which enters through shared access, so the window in which the map names
+        // trees the write has just deleted lies inside it and no search sees it; published after the
+        // write rather than from within it, so that an operation the storage replays publishes once,
+        // from the attempt which committed. The added indexes are named only at the end of that
+        // window rather than before the deletion, which costs nothing: the write above has just
+        // asked for them to be rebuilt, so nothing may read them until it has been.
+        indexingOptions = newIndexingOptions;
+        indexIdToIndexes = Collections.unmodifiableMap(newIndexIdToIndexes);
       }
       finally
       {
@@ -1020,11 +1027,22 @@ public void run(WriteableTransaction txn) throws Exception
       {
         updatedIndex.setIndexEntryLimit(newConfiguration.getIndexEntryLimit());
       }
+      // Published last: the entry limit this configuration declares reaches the indexes which stay
+      // only once the write which untrusts them has committed, so a configuration published before
+      // that would declare a limit those indexes do not hold yet.
+      config = newConfiguration;
     }
     catch (Exception e)
     {
+      // Logged as well as reported, for the reason given in the index delete listener of
+      // EntryContainer: what this index holds and what its configuration declares may no longer
+      // agree long after the session which asked for the change has ended.
+      final LocalizableMessage message = ERR_CONFIG_INDEX_CHANGE_FAILED.get(getAttributeType().getNameOrOID(),
+          entryContainer.getBaseDN(), StaticUtils.stackTraceToSingleLineString(e));
+      logger.error(message);
       ccr.setResultCode(DirectoryServer.getCoreConfigManager().getServerErrorResultCode());
-      ccr.addMessage(LocalizableMessage.raw(StaticUtils.stackTraceToSingleLineString(e)));
+      ccr.setAdminActionRequired(true);
+      ccr.addMessage(message);
     }
 
     return ccr;

opendj-server-legacy/src/main/java/org/opends/server/backends/pluggable/EntryContainer.java

@@ -268,8 +268,16 @@ public void run(WriteableTransaction txn) throws Exception
       }
       catch (Exception de)
       {
+        // The configuration entry naming those trees is gone and the storage still holds them, so
+        // this outlives the session which asked for the deletion: logged as well as reported. The
+        // framework logs the result too (ConfigurationHandler.handleConfigChangeResult), but as an
+        // argument of a message of its own, so only this call puts this message id in the error log.
+        final LocalizableMessage message = ERR_CONFIG_INDEX_DELETE_FAILED.get(
+            cfg.getAttribute().getNameOrOID(), getBaseDN(), StaticUtils.stackTraceToSingleLineString(de));
+        logger.error(message);
         ccr.setResultCode(getCoreConfigManager().getServerErrorResultCode());
-        ccr.addMessage(LocalizableMessage.raw(StaticUtils.stackTraceToSingleLineString(de)));
+        ccr.setAdminActionRequired(true);
+        ccr.addMessage(message);
       }
       finally
       {
@@ -369,8 +377,13 @@ public void run(WriteableTransaction txn) throws Exception
       }
       catch (Exception e)
       {
+        // Reported and logged for the reason given in the index delete listener above.
+        final LocalizableMessage message = ERR_CONFIG_VLV_INDEX_DELETE_FAILED.get(
+            cfg.getName(), getBaseDN(), StaticUtils.stackTraceToSingleLineString(e));
+        logger.error(message);
         ccr.setResultCode(getCoreConfigManager().getServerErrorResultCode());
-        ccr.addMessage(LocalizableMessage.raw(StaticUtils.stackTraceToSingleLineString(e)));
+        ccr.setAdminActionRequired(true);
+        ccr.addMessage(message);
       }
       finally
       {
@@ -2557,24 +2570,31 @@ public ConfigChangeResult applyConfigurationChange(final PluggableBackendCfg cfg
     EntryContainer.this.lock();
     try
     {
-      storage.write(new WriteOperation()
-      {
-        @Override
-        public void run(WriteableTransaction txn) throws Exception
-        {
-          id2entry.setDataConfig(newDataConfig(cfg));
-          EntryContainer.this.config = cfg;
-        }
-      });
+      // None of this is transactional: the entries and the indexes are handed the parameters to
+      // encode with from now on, and neither of those is a record in a tree. The storage.write which
+      // used to wrap it had a transactional body, removed long before the wrapper was; left behind,
+      // it was a transaction a bounded storage could give up on, and giving up between the entries
+      // and the indexes leaves the two encoded under settings which no longer agree. What can fail
+      // is done first, before anything has been changed; publishing to the other threads is what the
+      // entry container lock is held for here, and never was the transaction's doing.
+      final String cipherTransformation = cfg.getCipherTransformation();
+      final int cipherKeyLength = cfg.getCipherKeyLength();
+      final DataConfig dataConfig = newDataConfig(cfg);
+      id2entry.setDataConfig(dataConfig);
       for (CryptoSuite indexCrypto : attrCryptoMap.values())
       {
-        indexCrypto.newParameters(cfg.getCipherTransformation(), cfg.getCipherKeyLength(), indexCrypto.isEncrypted());
+        indexCrypto.newParameters(cipherTransformation, cipherKeyLength, indexCrypto.isEncrypted());
       }
+      EntryContainer.this.config = cfg;
     }
     catch (Exception e)
     {
+      final LocalizableMessage message =
+          ERR_CONFIG_BACKEND_DATA_CHANGE_FAILED.get(getBaseDN(), stackTraceToSingleLineString(e));
+      logger.error(message);
       ccr.setResultCode(DirectoryServer.getCoreConfigManager().getServerErrorResultCode());
-      ccr.addMessage(LocalizableMessage.raw(stackTraceToSingleLineString(e)));
+      ccr.setAdminActionRequired(true);
+      ccr.addMessage(message);
     }
     finally
     {

opendj-server-legacy/src/messages/org/opends/messages/backend.properties

@@ -1132,3 +1132,27 @@ ERR_BACKEND_BASEDN_NO_LONGER_HELD_623=The base DNs of backend %s could not be ch
  longer one this backend holds, which is what closing its root container leaves behind - an LDIF import, \
  an index rebuild, an LDIF export and the backend being disabled all do that. Nothing has been changed; \
  submit the change again once that has finished
+ERR_CONFIG_INDEX_DELETE_FAILED_624=The index for attribute '%s' of backend base DN '%s' was \
+ removed from the configuration, but the trees holding its data could not be deleted: %s. Those \
+ trees may still hold the data of that index, in whole or in part, and no configuration names them \
+ any more, so nothing will delete them and nothing will keep them up to date. An index created \
+ again for that attribute with the same settings adopts those trees and is considered trusted over \
+ their stale content, so it must be rebuilt before it is used
+ERR_CONFIG_VLV_INDEX_DELETE_FAILED_625=The VLV index '%s' of backend base DN '%s' was removed from \
+ the configuration, but the trees holding its data could not be deleted: %s. Those trees may still \
+ hold the data of that index, in whole or in part, and no configuration names them any more, so \
+ nothing will delete them and nothing will keep them up to date. A VLV index created again under \
+ the same name adopts those trees and is considered trusted over their stale content, so it must \
+ be rebuilt before it is used
+ERR_CONFIG_INDEX_CHANGE_FAILED_626=The configuration of the index for attribute '%s' of backend \
+ base DN '%s' could not be applied in full: %s. What this index holds and what its configuration \
+ declares may no longer agree, so this index must be rebuilt before it is used, after this backend \
+ has been disabled and enabled again so that every tree the stored configuration declares is named \
+ once more. The trees of the index types this change removed may still hold their data while no \
+ configuration names them any more, so nothing will delete them and nothing will keep them up to \
+ date; an index type declared again for that attribute adopts those trees and is considered trusted \
+ over their stale content, and must be rebuilt too
+ERR_CONFIG_BACKEND_DATA_CHANGE_FAILED_627=The compression, encoding and encryption settings of \
+ backend base DN '%s' could not be applied in full: %s. Its entries and its indexes may no longer \
+ be encoded under the same settings; disabling and enabling this backend builds both from the \
+ stored configuration again