Fix activity statistics log records

1) The import, reconciliation, and live sync activities did not call parent createReportingCharacteristics() method, so the upstream settings (namely, creation of run records) was not applied. Therefore, the wall-clock time and throughput was not measured for import and reconciliation tasks. (For live sync the run records are not created intentionally.) 2) When information about overall wall-clock time (obtained from run records) is missing, no "null" values are logged. This resolves MID-7585.
Evolveum · Jan 26, 2022 · 2aac863 · 2aac863
1 parent afcb044
commit 2aac863
Show file tree

Hide file tree

Showing 5 changed files with 25 additions and 11 deletions.
diff --git a/...impl/src/main/java/com/evolveum/midpoint/model/impl/sync/tasks/imp/ImportActivityRun.java b/...impl/src/main/java/com/evolveum/midpoint/model/impl/sync/tasks/imp/ImportActivityRun.java
@@ -48,7 +48,7 @@ public final class ImportActivityRun
 
     @Override
     public @NotNull ActivityReportingCharacteristics createReportingCharacteristics() {
-        return new ActivityReportingCharacteristics()
+        return super.createReportingCharacteristics()
                 .actionsExecutedStatisticsSupported(true)
                 .synchronizationStatisticsSupported(true);
     }

diff --git a/...n/java/com/evolveum/midpoint/model/impl/sync/tasks/recon/RemainingShadowsActivityRun.java b/...n/java/com/evolveum/midpoint/model/impl/sync/tasks/recon/RemainingShadowsActivityRun.java
@@ -66,7 +66,7 @@ public boolean doesRequireDirectRepositoryAccess() {
 
     @Override
     public @NotNull ActivityReportingCharacteristics createReportingCharacteristics() {
-        return new ActivityReportingCharacteristics()
+        return super.createReportingCharacteristics()
                 .actionsExecutedStatisticsSupported(true)
                 .synchronizationStatisticsSupported(false);
         // TODO We will eventually want to provide sync statistics even for this part, in order to see transitions

diff --git a/...olveum/midpoint/model/impl/sync/tasks/recon/ResourceObjectsReconciliationActivityRun.java b/...olveum/midpoint/model/impl/sync/tasks/recon/ResourceObjectsReconciliationActivityRun.java
@@ -51,7 +51,7 @@ public void beforeRun(OperationResult result) throws CommonException, ActivityRu
 
     @Override
     public @NotNull ActivityReportingCharacteristics createReportingCharacteristics() {
-        return new ActivityReportingCharacteristics()
+        return super.createReportingCharacteristics()
                 .actionsExecutedStatisticsSupported(true)
                 .synchronizationStatisticsSupported(true);
     }

diff --git a/...l/src/main/java/com/evolveum/midpoint/model/impl/sync/tasks/sync/LiveSyncActivityRun.java b/...l/src/main/java/com/evolveum/midpoint/model/impl/sync/tasks/sync/LiveSyncActivityRun.java
@@ -68,7 +68,7 @@ public LiveSyncActivityRun(
 
     @Override
     public @NotNull ActivityReportingCharacteristics createReportingCharacteristics() {
-        return new ActivityReportingCharacteristics()
+        return super.createReportingCharacteristics()
                 .determineOverallSizeDefault(ActivityOverallItemCountingOptionType.NEVER)
                 .bucketCompletionLoggingDefault(NONE) // To avoid log noise.
                 .actionsExecutedStatisticsSupported(true)

diff --git a/...common/src/main/java/com/evolveum/midpoint/repo/common/activity/run/StatisticsLogger.java b/...common/src/main/java/com/evolveum/midpoint/repo/common/activity/run/StatisticsLogger.java
@@ -89,14 +89,28 @@ void logBucketCompletion(boolean complete) {
                     current.getAverageTime(), current.getAverageWallClockTime(end), current.getThroughput(end));
         }
 
-        String overallBrief = String.format(Locale.US, "Overall: processed %,d objects in %.1f seconds, got %,d errors. Real progress: %,d.",
-                overall.getItemsProcessed(), ActivityItemProcessingStatisticsUtil.toSeconds(overall.getWallClockTime()),
-                overall.getErrors(), overall.getProgress());
+        Long wallClockTime = overall.getWallClockTime();
+
+        // Wall-clock time information is not available e.g. for activities with persistent state (like LiveSync)
+        boolean hasWallClockTime = wallClockTime != null && wallClockTime > 0;
+
+        String wallClockTimeString;
+        if (hasWallClockTime) {
+            wallClockTimeString = String.format(Locale.US, " in %.1f seconds", ActivityItemProcessingStatisticsUtil.toSeconds(wallClockTime));
+        } else {
+            wallClockTimeString = "";
+        }
+        String overallBrief = String.format(Locale.US,
+                "Overall: processed %,d objects%s, got %,d errors. Real progress: %,d.",
+                overall.getItemsProcessed(), wallClockTimeString, overall.getErrors(), overall.getProgress());
         if (overall.getItemsProcessed() > 0) {
-            overallBrief += String.format(Locale.US, " Average processing time for one object: %,.1f milliseconds. "
-                            + "Wall clock average: %,.1f milliseconds, throughput: %,.1f items per minute.",
-                    overall.getAverageTime(), overall.getAverageWallClockTime(),
-                    overall.getThroughput());
+            overallBrief += String.format(Locale.US,
+                    " Average processing time for one object: %,.1f milliseconds.", overall.getAverageTime());
+            if (hasWallClockTime && overall.getAverageWallClockTime() != null) {
+                overallBrief += String.format(Locale.US,
+                        " Wall clock average: %,.1f milliseconds, throughput: %,.1f items per minute.",
+                        overall.getAverageWallClockTime(), overall.getThroughput());
+            }
         }
 
         String mainMessageAddition = "\n" + currentBrief + "\n" + overallBrief;