From c619b097cac9f491d42640e5de0c432f4e4ea7d6 Mon Sep 17 00:00:00 2001
From: Michael Bien <mbien42@gmail.com>
Date: Thu, 11 Jul 2024 05:23:43 +0200
Subject: [PATCH] HintsInvoker logging improvements

 - print metrics to regular logger
 - add invocation count and cancelled state
 - sort by time spent before dump
---
 .../hints/spiimpl/hints/HintsInvoker.java     | 56 +++++++++++--------
 1 file changed, 32 insertions(+), 24 deletions(-)

diff --git a/java/spi.java.hints/src/org/netbeans/modules/java/hints/spiimpl/hints/HintsInvoker.java b/java/spi.java.hints/src/org/netbeans/modules/java/hints/spiimpl/hints/HintsInvoker.java
index aa13d2723055..186c99c0b46a 100644
--- a/java/spi.java.hints/src/org/netbeans/modules/java/hints/spiimpl/hints/HintsInvoker.java
+++ b/java/spi.java.hints/src/org/netbeans/modules/java/hints/spiimpl/hints/HintsInvoker.java
@@ -44,11 +44,14 @@
 import java.util.HashMap;
 import java.util.HashSet;
 import java.util.Iterator;
+import java.util.LinkedHashMap;
 import java.util.LinkedList;
 import java.util.List;
 import java.util.Map;
 import java.util.Map.Entry;
 import java.util.Set;
+import java.util.logging.Level;
+import java.util.logging.Logger;
 import javax.annotation.processing.ProcessingEnvironment;
 import javax.lang.model.SourceVersion;
 import javax.lang.model.type.TypeKind;
@@ -84,7 +87,9 @@
  */
 public class HintsInvoker {
 
-    private final Map<String, Long> timeLog = new HashMap<>();
+    private static final Logger LOG = Logger.getLogger(HintsInvoker.class.getName());
+
+    private final Map<String, Long> timeLog = new LinkedHashMap<>();
 
     private final HintsSettings settings;
     private final int caret;
@@ -160,7 +165,7 @@ private List<ErrorDescription> computeHints(CompilationInfo info, TreePath start
 
         List<ErrorDescription> errors = join(computeHints(info, startAt, descs, new ArrayList<>()));
 
-        dumpTimeSpentInHints();
+        printHintMetrics();
         
         return errors;
     }
@@ -721,14 +726,12 @@ private Collection<? extends ErrorDescription> runHint(HintDescription hd, HintC
     }
 
     private static <K, V> void merge(Map<K, List<V>> to, K key, Collection<? extends V> value) {
-        to.computeIfAbsent(key, k -> new LinkedList<>())
-          .addAll(value);
+        to.computeIfAbsent(key, k -> new LinkedList<>()).addAll(value);
     }
 
     private static <K, V> void mergeAll(Map<K, List<V>> to, Map<? extends K, ? extends Collection<? extends V>> what) {
         for (Entry<? extends K, ? extends Collection<? extends V>> e : what.entrySet()) {
-            to.computeIfAbsent(e.getKey(), k -> new LinkedList<>())
-              .addAll(e.getValue());
+            to.computeIfAbsent(e.getKey(), k -> new LinkedList<>()).addAll(e.getValue());
         }
     }
 
@@ -744,30 +747,35 @@ private static List<ErrorDescription> join(Map<?, ? extends List<? extends Error
         return result;
     }
 
-    private static final boolean logTimeSpentInHints = Boolean.getBoolean("java.HintsInvoker.time.in.hints");
-    private final Map<String, Long> hint2SpentTime = new HashMap<>();
+    private final Map<String, HintMetric> hint2SpentTime = new HashMap<>();
 
     private void reportSpentTime(String id, long nanoTime) {
-        if (!logTimeSpentInHints) return;
-        
-        Long prev = hint2SpentTime.get(id);
-
-        if (prev == null) {
-            prev = (long) 0;
+        if (!LOG.isLoggable(Level.FINE)) {
+            return;
         }
-
-        hint2SpentTime.put(id, prev + nanoTime);
+        HintMetric metric = hint2SpentTime.computeIfAbsent(id, k -> new HintMetric());
+        metric.invocations++;
+        metric.time += nanoTime;
+        metric.cancelled = cancel.get();
     }
 
-    private void dumpTimeSpentInHints() {
-        if (!logTimeSpentInHints) return;
-
-        List<Entry<String, Long>> l = new ArrayList<>(hint2SpentTime.entrySet());
-
-        l.sort((Entry<String, Long> o1, Entry<String, Long> o2) -> (int) Math.signum(o1.getValue() - o2.getValue()));
+    private void printHintMetrics() {
+        if (!LOG.isLoggable(Level.FINE)) {
+            return;
+        }
+        hint2SpentTime.entrySet().stream()
+            .sorted((e1, e2) -> Long.compare(e2.getValue().time, e1.getValue().time))
+            .forEach((e) -> LOG.fine(e.getValue() + ": " + e.getKey()));
+        LOG.fine("hint processing " + (cancel.get() ? "cancelled" : "complete")); // NOI18N
+    }
 
-        for (Entry<String, Long> e : l) {
-            System.err.println(e.getKey() + "=" + String.format("%3.2f", e.getValue() / 1000000.0));
+    private static final class HintMetric {
+        private long time;
+        private int invocations;
+        private boolean cancelled;
+        @Override
+        public String toString() {
+            return "{time=" + String.format("%3.2f", time / 1_000_000.0) + "ms, invocations=" + invocations + ", cancelled=" + cancelled + '}'; // NOI18N
         }
     }
 }