diff --git a/server/src/main/java/org/elasticsearch/repositories/blobstore/BlobStoreRepository.java b/server/src/main/java/org/elasticsearch/repositories/blobstore/BlobStoreRepository.java index fdac63cc5466c..d5ffa95bf87b8 100644 --- a/server/src/main/java/org/elasticsearch/repositories/blobstore/BlobStoreRepository.java +++ b/server/src/main/java/org/elasticsearch/repositories/blobstore/BlobStoreRepository.java @@ -94,6 +94,7 @@ import org.elasticsearch.core.RefCounted; import org.elasticsearch.core.Releasable; import org.elasticsearch.core.SuppressForbidden; +import org.elasticsearch.core.TimeValue; import org.elasticsearch.core.Tuple; import org.elasticsearch.index.IndexVersion; import org.elasticsearch.index.shard.ShardId; @@ -4223,11 +4224,12 @@ private void checkAborted() { final long uploadTimeInMillis = threadPool.rawRelativeTimeInMillis() - startMillis; blobStoreSnapshotMetrics.incrementCountersForPartUpload(partBytes, uploadTimeInMillis); logger.trace( - "[{}] Writing [{}] of size [{}b] to [{}] took [{}ms]", + "[{}] Writing [{}] of size [{}b] to [{}] took [{}/{}ms]", metadata.name(), partName, partBytes, shardContainer.path(), + new TimeValue(uploadTimeInMillis), uploadTimeInMillis ); } diff --git a/server/src/main/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTracker.java b/server/src/main/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTracker.java index 45f2fb96fce4e..53eb8f5fcd91b 100644 --- a/server/src/main/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTracker.java +++ b/server/src/main/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTracker.java @@ -15,6 +15,7 @@ import org.elasticsearch.common.Strings; import org.elasticsearch.common.settings.ClusterSettings; import org.elasticsearch.common.settings.Setting; +import org.elasticsearch.common.time.DateFormatter; import org.elasticsearch.common.util.concurrent.ConcurrentCollections; import org.elasticsearch.core.TimeValue; import org.elasticsearch.index.shard.ShardId; @@ -44,6 +45,7 @@ public class SnapshotShutdownProgressTracker { ); private static final Logger logger = LogManager.getLogger(SnapshotShutdownProgressTracker.class); + private static final DateFormatter DATE_TIME_FORMATTER = DateFormatter.forPattern("strict_date_optional_time"); private final Supplier getLocalNodeId; private final Consumer logIndexShardSnapshotStatuses; @@ -136,15 +138,17 @@ private void logProgressReport() { logger.info( """ Current active shard snapshot stats on data node [{}]. \ - Node shutdown cluster state update received at [{} millis]. \ - Finished signalling shard snapshots to pause at [{} millis]. \ + Node shutdown cluster state update received at [{} UTC]. \ + Finished signalling shard snapshots to pause at [{} UTC]. \ + Time between the node shutdown cluster state update and signalling shard snapshots to pause is [{} millis]. \ Number shard snapshots running [{}]. \ Number shard snapshots waiting for master node reply to status update request [{}] \ Shard snapshot completion stats since shutdown began: Done [{}]; Failed [{}]; Aborted [{}]; Paused [{}]\ """, getLocalNodeId.get(), - shutdownStartMillis, - shutdownFinishedSignallingPausingMillis, + DATE_TIME_FORMATTER.formatMillis(shutdownStartMillis), + DATE_TIME_FORMATTER.formatMillis(shutdownFinishedSignallingPausingMillis), + shutdownFinishedSignallingPausingMillis - shutdownStartMillis, numberOfShardSnapshotsInProgressOnDataNode.get(), shardSnapshotRequests.size(), doneCount.get(), diff --git a/server/src/test/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTrackerTests.java b/server/src/test/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTrackerTests.java index 8adcb3eb9d5f4..fbaf3105d1824 100644 --- a/server/src/test/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTrackerTests.java +++ b/server/src/test/java/org/elasticsearch/snapshots/SnapshotShutdownProgressTrackerTests.java @@ -16,6 +16,7 @@ import org.elasticsearch.common.settings.ClusterSettings; import org.elasticsearch.common.settings.Setting; import org.elasticsearch.common.settings.Settings; +import org.elasticsearch.common.time.DateFormatter; import org.elasticsearch.common.unit.ByteSizeValue; import org.elasticsearch.common.util.concurrent.DeterministicTaskQueue; import org.elasticsearch.core.TimeValue; @@ -271,12 +272,15 @@ public void testTrackerPauseTimestamp() { ); try (var mockLog = MockLog.capture(Coordinator.class, SnapshotShutdownProgressTracker.class)) { + long timeInMillis = testThreadPool.relativeTimeInMillis(); mockLog.addExpectation( new MockLog.SeenEventExpectation( "pausing timestamp should be set", SnapshotShutdownProgressTracker.class.getName(), Level.INFO, - "*Finished signalling shard snapshots to pause at [" + testThreadPool.relativeTimeInMillis() + " millis]*" + "*Finished signalling shard snapshots to pause at [" + + DateFormatter.forPattern("strict_date_optional_time").formatMillis(timeInMillis) + + " UTC]*" ) );