Replace cached time with system clock in MasterService debug logs

Signed-off-by: Sandesh Kumar <[email protected]>
opensearch-project · Jun 2, 2023 · dd26f70 · dd26f70
1 parent 3afb36f
commit dd26f70
Show file tree

Hide file tree

Showing 2 changed files with 7 additions and 6 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -94,6 +94,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
 ### Changed
 - Replace jboss-annotations-api_1.2_spec with jakarta.annotation-api ([#7836](https://github.com/opensearch-project/OpenSearch/pull/7836))
 - Add min, max, average and thread info to resource stats in tasks API ([#7673](https://github.com/opensearch-project/OpenSearch/pull/7673))
+- MasterService Debug logs for computation time to use system clock time instead of cached time
 
 ### Deprecated
 

diff --git a/server/src/main/java/org/opensearch/cluster/service/MasterService.java b/server/src/main/java/org/opensearch/cluster/service/MasterService.java
@@ -291,14 +291,14 @@ private void runTasks(TaskInputs taskInputs) {
             return;
         }
 
-        final long computationStartTime = threadPool.relativeTimeInMillis();
+        final long computationStartTime = System.nanoTime();
         final TaskOutputs taskOutputs = calculateTaskOutputs(taskInputs, previousClusterState);
         taskOutputs.notifyFailedTasks();
         final TimeValue computationTime = getTimeSince(computationStartTime);
         logExecutionTime(computationTime, "compute cluster state update", summary);
 
         if (taskOutputs.clusterStateUnchanged()) {
-            final long notificationStartTime = threadPool.relativeTimeInMillis();
+            final long notificationStartTime = System.nanoTime();
             taskOutputs.notifySuccessfulTasksOnUnchangedClusterState();
             final TimeValue executionTime = getTimeSince(notificationStartTime);
             logExecutionTime(executionTime, "notify listeners on unchanged cluster state", summary);
@@ -309,7 +309,7 @@ private void runTasks(TaskInputs taskInputs) {
             } else {
                 logger.debug("cluster state updated, version [{}], source [{}]", newClusterState.version(), summary);
             }
-            final long publicationStartTime = threadPool.relativeTimeInMillis();
+            final long publicationStartTime = System.nanoTime();
             try {
                 ClusterChangedEvent clusterChangedEvent = new ClusterChangedEvent(summary, newClusterState, previousClusterState);
                 // new cluster state, notify all listeners
@@ -335,8 +335,8 @@ private void runTasks(TaskInputs taskInputs) {
         }
     }
 
-    private TimeValue getTimeSince(long startTimeMillis) {
-        return TimeValue.timeValueMillis(Math.max(0, threadPool.relativeTimeInMillis() - startTimeMillis));
+    private TimeValue getTimeSince(long startTimeNanos) {
+        return TimeValue.timeValueMillis(TimeValue.nsecToMSec(System.nanoTime() - startTimeNanos));
     }
 
     protected void publish(ClusterChangedEvent clusterChangedEvent, TaskOutputs taskOutputs, long startTimeMillis) {
@@ -358,7 +358,7 @@ protected boolean blockingAllowed() {
     }
 
     void onPublicationSuccess(ClusterChangedEvent clusterChangedEvent, TaskOutputs taskOutputs) {
-        final long notificationStartTime = threadPool.relativeTimeInMillis();
+        final long notificationStartTime = System.nanoTime();
         taskOutputs.processedDifferentClusterState(clusterChangedEvent.previousState(), clusterChangedEvent.state());
 
         try {