More detailed tracing during writing metadata

Packaging tests are occasionally failing (elastic#30295) because of very slow index
template creation. It looks like the slow part is updating the on-disk cluster
state, and this change will help to confirm this.

Author: DaveCTurner

server/src/main/java/org/elasticsearch/gateway/MetaDataStateFormat.java

@@ -29,6 +29,7 @@
 import org.apache.lucene.store.IndexInput;
 import org.apache.lucene.store.OutputStreamIndexOutput;
 import org.apache.lucene.store.SimpleFSDirectory;
+import org.elasticsearch.common.logging.Loggers;
 import org.elasticsearch.core.internal.io.IOUtils;
 import org.elasticsearch.ExceptionsHelper;
 import org.elasticsearch.common.bytes.BytesArray;
@@ -76,6 +77,7 @@ public abstract class MetaDataStateFormat<T> {
     private final String prefix;
     private final Pattern stateFilePattern;
 
+    private static final Logger logger = Loggers.getLogger(MetaDataStateFormat.class);
 
     /**
      * Creates a new {@link MetaDataStateFormat} instance
@@ -134,6 +136,7 @@ public void close() throws IOException {
             IOUtils.fsync(tmpStatePath, false); // fsync the state file
             Files.move(tmpStatePath, finalStatePath, StandardCopyOption.ATOMIC_MOVE);
             IOUtils.fsync(stateLocation, true);
+            logger.trace("written state to {}", finalStatePath);
             for (int i = 1; i < locations.length; i++) {
                 stateLocation = locations[i].resolve(STATE_DIR_NAME);
                 Files.createDirectories(stateLocation);
@@ -145,6 +148,7 @@ public void close() throws IOException {
                     // we are on the same FileSystem / Partition here we can do an atomic move
                     Files.move(tmpPath, finalPath, StandardCopyOption.ATOMIC_MOVE);
                     IOUtils.fsync(stateLocation, true);
+                    logger.trace("copied state to {}", finalPath);
                 } finally {
                     Files.deleteIfExists(tmpPath);
                 }

server/src/main/java/org/elasticsearch/gateway/MetaStateService.java

@@ -123,6 +123,7 @@ public void writeIndex(String reason, IndexMetaData indexMetaData) throws IOExce
         try {
             IndexMetaData.FORMAT.write(indexMetaData,
                 nodeEnv.indexPaths(indexMetaData.getIndex()));
+            logger.trace("[{}] state written", index);
         } catch (Exception ex) {
             logger.warn(() -> new ParameterizedMessage("[{}]: failed to write index state", index), ex);
             throw new IOException("failed to write state for [" + index + "]", ex);
@@ -136,6 +137,7 @@ void writeGlobalState(String reason, MetaData metaData) throws IOException {
         logger.trace("[_global] writing state, reason [{}]",  reason);
         try {
             MetaData.FORMAT.write(metaData, nodeEnv.nodeDataPaths());
+            logger.trace("[_global] state written");
         } catch (Exception ex) {
             logger.warn("[_global]: failed to write global state", ex);
             throw new IOException("failed to write global state", ex);