Add yet more logging around index creation (#46431)

Further investigation into #46091, expanding on #46363, to add even more
detailed logging around the retry behaviour during index creation.

Author: DaveCTurner

buildSrc/src/main/java/org/elasticsearch/gradle/testclusters/ElasticsearchNode.java

@@ -965,8 +965,15 @@ private void createConfiguration() {
         defaultConfig.put("discovery.initial_state_timeout", "0s");
 
         // TODO: Remove these once https://github.com/elastic/elasticsearch/issues/46091 is fixed
-        defaultConfig.put("logger.org.elasticsearch.action.support.master", "DEBUG");
+        defaultConfig.put("logger.org.elasticsearch.action.support.master.TransportMasterNodeAction", "TRACE");
+        defaultConfig.put("logger.org.elasticsearch.cluster.metadata.MetaDataCreateIndexService", "TRACE");
+        defaultConfig.put("logger.org.elasticsearch.cluster.service", "DEBUG");
         defaultConfig.put("logger.org.elasticsearch.cluster.coordination", "DEBUG");
+        defaultConfig.put("logger.org.elasticsearch.gateway.MetaStateService", "TRACE");
+        if (getVersion().getMajor() >= 8) {
+            defaultConfig.put("cluster.service.slow_task_logging_threshold", "5s");
+            defaultConfig.put("cluster.service.slow_master_task_logging_threshold", "5s");
+        }
 
         HashSet<String> overriden = new HashSet<>(defaultConfig.keySet());
         overriden.retainAll(settings.keySet());

server/src/main/java/org/elasticsearch/action/admin/cluster/allocation/TransportClusterAllocationExplainAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.cluster.allocation;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
 import org.elasticsearch.action.support.master.TransportMasterNodeAction;
@@ -56,6 +58,8 @@
 public class TransportClusterAllocationExplainAction
         extends TransportMasterNodeAction<ClusterAllocationExplainRequest, ClusterAllocationExplainResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportClusterAllocationExplainAction.class);
+
     private final ClusterInfoService clusterInfoService;
     private final AllocationDeciders allocationDeciders;
     private final ShardsAllocator shardAllocator;

server/src/main/java/org/elasticsearch/action/admin/cluster/configuration/TransportAddVotingConfigExclusionsAction.java

@@ -18,6 +18,8 @@
  */
 package org.elasticsearch.action.admin.cluster.configuration;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.elasticsearch.ElasticsearchException;
 import org.elasticsearch.ElasticsearchTimeoutException;
 import org.elasticsearch.action.ActionListener;
@@ -53,6 +55,8 @@
 public class TransportAddVotingConfigExclusionsAction extends TransportMasterNodeAction<AddVotingConfigExclusionsRequest,
     AddVotingConfigExclusionsResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportAddVotingConfigExclusionsAction.class);
+
     public static final Setting<Integer> MAXIMUM_VOTING_CONFIG_EXCLUSIONS_SETTING
         = Setting.intSetting("cluster.max_voting_config_exclusions", 10, 1, Property.Dynamic, Property.NodeScope);
 

server/src/main/java/org/elasticsearch/action/admin/cluster/configuration/TransportClearVotingConfigExclusionsAction.java

@@ -18,6 +18,8 @@
  */
 package org.elasticsearch.action.admin.cluster.configuration;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.elasticsearch.ElasticsearchException;
 import org.elasticsearch.ElasticsearchTimeoutException;
 import org.elasticsearch.action.ActionListener;
@@ -49,6 +51,8 @@
 public class TransportClearVotingConfigExclusionsAction
     extends TransportMasterNodeAction<ClearVotingConfigExclusionsRequest, ClearVotingConfigExclusionsResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportClearVotingConfigExclusionsAction.class);
+
     @Inject
     public TransportClearVotingConfigExclusionsAction(TransportService transportService, ClusterService clusterService,
                                                       ThreadPool threadPool, ActionFilters actionFilters,

server/src/main/java/org/elasticsearch/action/admin/cluster/settings/TransportClusterUpdateSettingsAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.cluster.settings;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.ElasticsearchException;
 import org.elasticsearch.action.ActionListener;
@@ -47,6 +49,8 @@
 public class TransportClusterUpdateSettingsAction extends
     TransportMasterNodeAction<ClusterUpdateSettingsRequest, ClusterUpdateSettingsResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportClusterUpdateSettingsAction.class);
+
     private final AllocationService allocationService;
 
     private final ClusterSettings clusterSettings;

server/src/main/java/org/elasticsearch/action/admin/cluster/snapshots/status/TransportSnapshotsStatusAction.java

@@ -21,6 +21,8 @@
 
 import com.carrotsearch.hppc.cursors.ObjectCursor;
 import com.carrotsearch.hppc.cursors.ObjectObjectCursor;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.ActionRunnable;
 import org.elasticsearch.action.support.ActionFilters;
@@ -62,6 +64,8 @@
 
 public class TransportSnapshotsStatusAction extends TransportMasterNodeAction<SnapshotsStatusRequest, SnapshotsStatusResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportSnapshotsStatusAction.class);
+
     private final SnapshotsService snapshotsService;
 
     private final NodeClient client;

server/src/main/java/org/elasticsearch/action/admin/cluster/tasks/TransportPendingClusterTasksAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.cluster.tasks;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
 import org.elasticsearch.action.support.master.TransportMasterNodeReadAction;
@@ -39,6 +41,8 @@
 public class TransportPendingClusterTasksAction
         extends TransportMasterNodeReadAction<PendingClusterTasksRequest, PendingClusterTasksResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportPendingClusterTasksAction.class);
+
     private final ClusterService clusterService;
 
     @Inject

server/src/main/java/org/elasticsearch/action/admin/indices/alias/TransportIndicesAliasesAction.java

@@ -20,6 +20,8 @@
 package org.elasticsearch.action.admin.indices.alias;
 
 import com.carrotsearch.hppc.cursors.ObjectCursor;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.RequestValidators;
 import org.elasticsearch.action.admin.indices.alias.IndicesAliasesRequest.AliasActions;
@@ -61,6 +63,8 @@
  */
 public class TransportIndicesAliasesAction extends TransportMasterNodeAction<IndicesAliasesRequest, AcknowledgedResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportIndicesAliasesAction.class);
+
     private final MetaDataIndexAliasesService indexAliasesService;
     private final RequestValidators<IndicesAliasesRequest> requestValidators;
 

server/src/main/java/org/elasticsearch/action/admin/indices/close/TransportCloseIndexAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.indices.close;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
@@ -49,6 +51,8 @@
  */
 public class TransportCloseIndexAction extends TransportMasterNodeAction<CloseIndexRequest, CloseIndexResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportCloseIndexAction.class);
+
     private final MetaDataIndexStateService indexStateService;
     private final DestructiveOperations destructiveOperations;
     private volatile boolean closeIndexEnabled;

server/src/main/java/org/elasticsearch/action/admin/indices/create/CreateIndexClusterStateUpdateRequest.java

@@ -147,4 +147,19 @@ public boolean copySettings() {
         return copySettings;
     }
 
+    @Override
+    public String toString() {
+        return "CreateIndexClusterStateUpdateRequest{" +
+            "cause='" + cause + '\'' +
+            ", index='" + index + '\'' +
+            ", providedName='" + providedName + '\'' +
+            ", recoverFrom=" + recoverFrom +
+            ", resizeType=" + resizeType +
+            ", copySettings=" + copySettings +
+            ", settings=" + settings +
+            ", aliases=" + aliases +
+            ", blocks=" + blocks +
+            ", waitForActiveShards=" + waitForActiveShards +
+            '}';
+    }
 }

server/src/main/java/org/elasticsearch/action/admin/indices/delete/TransportDeleteIndexAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.indices.delete;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
@@ -48,6 +50,8 @@
  */
 public class TransportDeleteIndexAction extends TransportMasterNodeAction<DeleteIndexRequest, AcknowledgedResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportDeleteIndexAction.class);
+
     private final MetaDataDeleteIndexService deleteIndexService;
     private final DestructiveOperations destructiveOperations;
 

server/src/main/java/org/elasticsearch/action/admin/indices/mapping/get/TransportGetMappingsAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.indices.mapping.get;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
 import org.elasticsearch.action.support.master.info.TransportClusterInfoAction;
@@ -39,6 +41,8 @@
 
 public class TransportGetMappingsAction extends TransportClusterInfoAction<GetMappingsRequest, GetMappingsResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportGetMappingsAction.class);
+
     private final IndicesService indicesService;
 
     @Inject

server/src/main/java/org/elasticsearch/action/admin/indices/mapping/put/TransportPutMappingAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.indices.mapping.put;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.RequestValidators;
@@ -49,6 +51,8 @@
  */
 public class TransportPutMappingAction extends TransportMasterNodeAction<PutMappingRequest, AcknowledgedResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportPutMappingAction.class);
+
     private final MetaDataMappingService metaDataMappingService;
     private final RequestValidators<PutMappingRequest> requestValidators;
 

server/src/main/java/org/elasticsearch/action/admin/indices/open/TransportOpenIndexAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.indices.open;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
@@ -45,6 +47,8 @@
  */
 public class TransportOpenIndexAction extends TransportMasterNodeAction<OpenIndexRequest, OpenIndexResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportOpenIndexAction.class);
+
     private final MetaDataIndexStateService indexStateService;
     private final DestructiveOperations destructiveOperations;
 

server/src/main/java/org/elasticsearch/action/admin/indices/settings/put/TransportUpdateSettingsAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.indices.settings.put;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
@@ -43,6 +45,8 @@
 
 public class TransportUpdateSettingsAction extends TransportMasterNodeAction<UpdateSettingsRequest, AcknowledgedResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportUpdateSettingsAction.class);
+
     private final MetaDataUpdateSettingsService updateSettingsService;
 
     @Inject

server/src/main/java/org/elasticsearch/action/admin/indices/shards/TransportIndicesShardStoresAction.java

@@ -18,6 +18,7 @@
  */
 package org.elasticsearch.action.admin.indices.shards;
 
+import org.apache.logging.log4j.LogManager;
 import org.apache.logging.log4j.Logger;
 import org.apache.lucene.util.CollectionUtil;
 import org.elasticsearch.action.ActionListener;
@@ -70,6 +71,8 @@
 public class TransportIndicesShardStoresAction
         extends TransportMasterNodeReadAction<IndicesShardStoresRequest, IndicesShardStoresResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportIndicesShardStoresAction.class);
+
     private final NodeClient client;
 
     @Inject

server/src/main/java/org/elasticsearch/action/admin/indices/template/delete/TransportDeleteIndexTemplateAction.java

@@ -18,6 +18,8 @@
  */
 package org.elasticsearch.action.admin.indices.template.delete;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
@@ -43,6 +45,8 @@
 public class TransportDeleteIndexTemplateAction
         extends TransportMasterNodeAction<DeleteIndexTemplateRequest, AcknowledgedResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportDeleteIndexTemplateAction.class);
+
     private final MetaDataIndexTemplateService indexTemplateService;
 
     @Inject

server/src/main/java/org/elasticsearch/action/admin/indices/template/put/TransportPutIndexTemplateAction.java

@@ -18,6 +18,8 @@
  */
 package org.elasticsearch.action.admin.indices.template.put;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
@@ -45,6 +47,8 @@
  */
 public class TransportPutIndexTemplateAction extends TransportMasterNodeAction<PutIndexTemplateRequest, AcknowledgedResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportPutIndexTemplateAction.class);
+
     private final MetaDataIndexTemplateService indexTemplateService;
     private final IndexScopedSettings indexScopedSettings;
 

server/src/main/java/org/elasticsearch/action/admin/indices/upgrade/post/TransportUpgradeSettingsAction.java

@@ -19,6 +19,8 @@
 
 package org.elasticsearch.action.admin.indices.upgrade.post;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.action.support.ActionFilters;
@@ -41,6 +43,8 @@
 
 public class TransportUpgradeSettingsAction extends TransportMasterNodeAction<UpgradeSettingsRequest, AcknowledgedResponse> {
 
+    private static final Logger logger = LogManager.getLogger(TransportUpgradeSettingsAction.class);
+
     private final MetaDataUpdateSettingsService updateSettingsService;
 
     @Inject