Pass field definitions into metric timers

This makes the names of the fields available to the Timer so that the
fields names can be included into debug logs and performance logs.

Change-Id: I987f40da0165ac948f2747b33cb8154f3bdab4da
Signed-off-by: Edwin Kempin <ekempin@google.com>

java/com/google/gerrit/metrics/DisabledMetricMaker.java

@@ -79,7 +79,7 @@ public class DisabledMetricMaker extends MetricMaker {
 
   @Override
   public <F1> Timer1<F1> newTimer(String name, Description desc, Field<F1> field1) {
-    return new Timer1<F1>(name) {
+    return new Timer1<F1>(name, field1) {
       @Override
       protected void doRecord(F1 field1, long value, TimeUnit unit) {}
 
@@ -91,7 +91,7 @@ public class DisabledMetricMaker extends MetricMaker {
   @Override
   public <F1, F2> Timer2<F1, F2> newTimer(
       String name, Description desc, Field<F1> field1, Field<F2> field2) {
-    return new Timer2<F1, F2>(name) {
+    return new Timer2<F1, F2>(name, field1, field2) {
       @Override
       protected void doRecord(F1 field1, F2 field2, long value, TimeUnit unit) {}
 
@@ -103,7 +103,7 @@ public class DisabledMetricMaker extends MetricMaker {
   @Override
   public <F1, F2, F3> Timer3<F1, F2, F3> newTimer(
       String name, Description desc, Field<F1> field1, Field<F2> field2, Field<F3> field3) {
-    return new Timer3<F1, F2, F3>(name) {
+    return new Timer3<F1, F2, F3>(name, field1, field2, field3) {
       @Override
       protected void doRecord(F1 field1, F2 field2, F3 field3, long value, TimeUnit unit) {}
 

java/com/google/gerrit/metrics/Timer1.java

@@ -39,61 +39,62 @@ public abstract class Timer1<F1> implements RegistrationHandle {
 
   public static class Context extends TimerContext {
     private final Timer1<Object> timer;
-    private final Object field1;
+    private final Object fieldValue;
 
     @SuppressWarnings("unchecked")
-    <F1> Context(Timer1<F1> timer, F1 field1) {
+    <F1> Context(Timer1<F1> timer, F1 fieldValue) {
       this.timer = (Timer1<Object>) timer;
-      this.field1 = field1;
+      this.fieldValue = fieldValue;
     }
 
     @Override
     public void record(long elapsed) {
-      timer.record(field1, elapsed, NANOSECONDS);
+      timer.record(fieldValue, elapsed, NANOSECONDS);
     }
   }
 
   protected final String name;
+  protected final Field<F1> field;
 
-  public Timer1(String name) {
+  public Timer1(String name, Field<F1> field) {
     this.name = name;
+    this.field = field;
   }
 
   /**
    * Begin a timer for the current block, value will be recorded when closed.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue bucket to record the timer
    * @return timer context
    */
-  public Context start(F1 field1) {
+  public Context start(F1 fieldValue) {
-    return new Context(this, field1);
+    return new Context(this, fieldValue);
   }
 
   /**
    * Record a value in the distribution.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue bucket to record the timer
    * @param value value to record
    * @param unit time unit of the value
    */
-  public final void record(F1 field1, long value, TimeUnit unit) {
+  public final void record(F1 fieldValue, long value, TimeUnit unit) {
     long durationMs = unit.toMillis(value);
 
-    // TODO(ekempin): We don't know the field name here. Check whether we can make it available.
     LoggingContext.getInstance()
         .addPerformanceLogRecord(
-            () -> PerformanceLogRecord.create(name, durationMs, "field1", field1));
+            () -> PerformanceLogRecord.create(name, durationMs, field.name(), fieldValue));
 
-    logger.atFinest().log("%s (%s) took %dms", name, field1, durationMs);
+    logger.atFinest().log("%s (%s = %s) took %dms", name, field.name(), fieldValue, durationMs);
-    doRecord(field1, value, unit);
+    doRecord(fieldValue, value, unit);
   }
 
   /**
    * Record a value in the distribution.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue bucket to record the timer
    * @param value value to record
    * @param unit time unit of the value
    */
-  protected abstract void doRecord(F1 field1, long value, TimeUnit unit);
+  protected abstract void doRecord(F1 fieldValue, long value, TimeUnit unit);
 }

java/com/google/gerrit/metrics/Timer2.java

@@ -40,67 +40,73 @@ public abstract class Timer2<F1, F2> implements RegistrationHandle {
 
   public static class Context extends TimerContext {
     private final Timer2<Object, Object> timer;
-    private final Object field1;
+    private final Object fieldValue1;
-    private final Object field2;
+    private final Object fieldValue2;
 
     @SuppressWarnings("unchecked")
-    <F1, F2> Context(Timer2<F1, F2> timer, F1 field1, F2 field2) {
+    <F1, F2> Context(Timer2<F1, F2> timer, F1 fieldValue1, F2 fieldValue2) {
       this.timer = (Timer2<Object, Object>) timer;
-      this.field1 = field1;
+      this.fieldValue1 = fieldValue1;
-      this.field2 = field2;
+      this.fieldValue2 = fieldValue2;
     }
 
     @Override
     public void record(long elapsed) {
-      timer.record(field1, field2, elapsed, NANOSECONDS);
+      timer.record(fieldValue1, fieldValue2, elapsed, NANOSECONDS);
     }
   }
 
   protected final String name;
+  protected final Field<F1> field1;
+  protected final Field<F2> field2;
 
-  public Timer2(String name) {
+  public Timer2(String name, Field<F1> field1, Field<F2> field2) {
     this.name = name;
+    this.field1 = field1;
+    this.field2 = field2;
   }
 
   /**
    * Begin a timer for the current block, value will be recorded when closed.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue1 bucket to record the timer
-   * @param field2 bucket to record the timer
+   * @param fieldValue2 bucket to record the timer
    * @return timer context
    */
-  public Context start(F1 field1, F2 field2) {
+  public Context start(F1 fieldValue1, F2 fieldValue2) {
-    return new Context(this, field1, field2);
+    return new Context(this, fieldValue1, fieldValue2);
   }
 
   /**
    * Record a value in the distribution.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue1 bucket to record the timer
-   * @param field2 bucket to record the timer
+   * @param fieldValue2 bucket to record the timer
    * @param value value to record
    * @param unit time unit of the value
    */
-  public final void record(F1 field1, F2 field2, long value, TimeUnit unit) {
+  public final void record(F1 fieldValue1, F2 fieldValue2, long value, TimeUnit unit) {
     long durationMs = unit.toMillis(value);
 
-    // TODO(ekempin): We don't know the field names here. Check whether we can make them available.
     LoggingContext.getInstance()
         .addPerformanceLogRecord(
             () ->
-                PerformanceLogRecord.create(name, durationMs, "field1", field1, "field2", field2));
+                PerformanceLogRecord.create(
+                    name, durationMs, field1.name(), fieldValue1, field2.name(), fieldValue2));
 
-    logger.atFinest().log("%s (%s, %s) took %dms", name, field1, field2, durationMs);
+    logger.atFinest().log(
-    doRecord(field1, field2, value, unit);
+        "%s (%s = %s, %s = %s) took %dms",
+        name, field1.name(), fieldValue1, field2.name(), fieldValue2, durationMs);
+    doRecord(fieldValue1, fieldValue2, value, unit);
   }
 
   /**
    * Record a value in the distribution.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue1 bucket to record the timer
-   * @param field2 bucket to record the timer
+   * @param fieldValue2 bucket to record the timer
    * @param value value to record
    * @param unit time unit of the value
    */
-  protected abstract void doRecord(F1 field1, F2 field2, long value, TimeUnit unit);
+  protected abstract void doRecord(F1 fieldValue1, F2 fieldValue2, long value, TimeUnit unit);
 }

java/com/google/gerrit/metrics/Timer3.java

@@ -41,73 +41,96 @@ public abstract class Timer3<F1, F2, F3> implements RegistrationHandle {
 
   public static class Context extends TimerContext {
     private final Timer3<Object, Object, Object> timer;
-    private final Object field1;
+    private final Object fieldValue1;
-    private final Object field2;
+    private final Object fieldValue2;
-    private final Object field3;
+    private final Object fieldValue3;
 
     @SuppressWarnings("unchecked")
     <F1, F2, F3> Context(Timer3<F1, F2, F3> timer, F1 f1, F2 f2, F3 f3) {
       this.timer = (Timer3<Object, Object, Object>) timer;
-      this.field1 = f1;
+      this.fieldValue1 = f1;
-      this.field2 = f2;
+      this.fieldValue2 = f2;
-      this.field3 = f3;
+      this.fieldValue3 = f3;
     }
 
     @Override
     public void record(long elapsed) {
-      timer.record(field1, field2, field3, elapsed, NANOSECONDS);
+      timer.record(fieldValue1, fieldValue2, fieldValue3, elapsed, NANOSECONDS);
     }
   }
 
   protected final String name;
+  protected final Field<F1> field1;
+  protected final Field<F2> field2;
+  protected final Field<F3> field3;
 
-  public Timer3(String name) {
+  public Timer3(String name, Field<F1> field1, Field<F2> field2, Field<F3> field3) {
     this.name = name;
+    this.field1 = field1;
+    this.field2 = field2;
+    this.field3 = field3;
   }
 
   /**
    * Begin a timer for the current block, value will be recorded when closed.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue1 bucket to record the timer
-   * @param field2 bucket to record the timer
+   * @param fieldValue2 bucket to record the timer
-   * @param field3 bucket to record the timer
+   * @param fieldValue3 bucket to record the timer
    * @return timer context
    */
-  public Context start(F1 field1, F2 field2, F3 field3) {
+  public Context start(F1 fieldValue1, F2 fieldValue2, F3 fieldValue3) {
-    return new Context(this, field1, field2, field3);
+    return new Context(this, fieldValue1, fieldValue2, fieldValue3);
   }
 
   /**
    * Record a value in the distribution.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue1 bucket to record the timer
-   * @param field2 bucket to record the timer
+   * @param fieldValue2 bucket to record the timer
-   * @param field3 bucket to record the timer
+   * @param fieldValue3 bucket to record the timer
    * @param value value to record
    * @param unit time unit of the value
    */
-  public final void record(F1 field1, F2 field2, F3 field3, long value, TimeUnit unit) {
+  public final void record(
+      F1 fieldValue1, F2 fieldValue2, F3 fieldValue3, long value, TimeUnit unit) {
     long durationMs = unit.toMillis(value);
 
-    // TODO(ekempin): We don't know the field names here. Check whether we can make them available.
     LoggingContext.getInstance()
         .addPerformanceLogRecord(
             () ->
                 PerformanceLogRecord.create(
-                    name, durationMs, "field1", field1, "field2", field2, "field3", field3));
+                    name,
+                    durationMs,
+                    field1.name(),
+                    fieldValue1,
+                    field2.name(),
+                    fieldValue2,
+                    field3.name(),
+                    fieldValue3));
 
-    logger.atFinest().log("%s (%s, %s, %s) took %dms", name, field1, field2, field3, durationMs);
+    logger.atFinest().log(
-    doRecord(field1, field2, field3, value, unit);
+        "%s (%s = %s, %s = %s, %s = %s) took %dms",
+        name,
+        field1.name(),
+        fieldValue1,
+        field2.name(),
+        fieldValue2,
+        field3.name(),
+        fieldValue3,
+        durationMs);
+    doRecord(fieldValue1, fieldValue2, fieldValue3, value, unit);
   }
 
   /**
    * Record a value in the distribution.
    *
-   * @param field1 bucket to record the timer
+   * @param fieldValue1 bucket to record the timer
-   * @param field2 bucket to record the timer
+   * @param fieldValue2 bucket to record the timer
-   * @param field3 bucket to record the timer
+   * @param fieldValue3 bucket to record the timer
    * @param value value to record
    * @param unit time unit of the value
    */
-  protected abstract void doRecord(F1 field1, F2 field2, F3 field3, long value, TimeUnit unit);
+  protected abstract void doRecord(
+      F1 fieldValue1, F2 fieldValue2, F3 fieldValue3, long value, TimeUnit unit);
 }

java/com/google/gerrit/metrics/dropwizard/TimerImpl1.java

@@ -26,8 +26,9 @@ class TimerImpl1<F1> extends BucketedTimer implements BucketedMetric {
     super(metrics, name, desc, field1);
   }
 
+  @SuppressWarnings("unchecked")
   Timer1<F1> timer() {
-    return new Timer1<F1>(name) {
+    return new Timer1<F1>(name, (Field<F1>) fields[0]) {
       @Override
       protected void doRecord(F1 field1, long value, TimeUnit unit) {
         total.record(value, unit);

java/com/google/gerrit/metrics/dropwizard/TimerImplN.java

@@ -29,8 +29,9 @@ class TimerImplN extends BucketedTimer implements BucketedMetric {
     super(metrics, name, desc, fields);
   }
 
+  @SuppressWarnings("unchecked")
   <F1, F2> Timer2<F1, F2> timer2() {
-    return new Timer2<F1, F2>(name) {
+    return new Timer2<F1, F2>(name, (Field<F1>) fields[0], (Field<F2>) fields[1]) {
       @Override
       protected void doRecord(F1 field1, F2 field2, long value, TimeUnit unit) {
         total.record(value, unit);
@@ -44,8 +45,10 @@ class TimerImplN extends BucketedTimer implements BucketedMetric {
     };
   }
 
+  @SuppressWarnings("unchecked")
   <F1, F2, F3> Timer3<F1, F2, F3> timer3() {
-    return new Timer3<F1, F2, F3>(name) {
+    return new Timer3<F1, F2, F3>(
+        name, (Field<F1>) fields[0], (Field<F2>) fields[1], (Field<F3>) fields[2]) {
       @Override
       protected void doRecord(F1 field1, F2 field2, F3 field3, long value, TimeUnit unit) {
         total.record(value, unit);

javatests/com/google/gerrit/server/logging/PerformanceLogContextTest.java

@@ -257,18 +257,18 @@ public class PerformanceLogContextTest {
         .containsExactly(
             PerformanceLogEntry.create("test1/latency", ImmutableMap.of()),
             PerformanceLogEntry.create(
-                "test2/latency", ImmutableMap.of("field1", Optional.of("value1"))),
+                "test2/latency", ImmutableMap.of("foo", Optional.of("value1"))),
             PerformanceLogEntry.create(
                 "test3/latency",
-                ImmutableMap.of("field1", Optional.of("value1"), "field2", Optional.of("value2"))),
+                ImmutableMap.of("foo", Optional.of("value1"), "bar", Optional.of("value2"))),
             PerformanceLogEntry.create(
                 "test4/latency",
                 ImmutableMap.of(
-                    "field1",
+                    "foo",
                     Optional.of("value1"),
-                    "field2",
+                    "bar",
                     Optional.of("value2"),
-                    "field3",
+                    "baz",
                     Optional.of("value3"))))
         .inOrder();
 
@@ -314,20 +314,13 @@ public class PerformanceLogContextTest {
 
     assertThat(testPerformanceLogger.logEntries())
         .containsExactly(
+            PerformanceLogEntry.create("test1/latency", ImmutableMap.of("foo", Optional.empty())),
             PerformanceLogEntry.create(
-                "test1/latency", ImmutableMap.of("field1", Optional.empty())),
+                "test2/latency", ImmutableMap.of("foo", Optional.empty(), "bar", Optional.empty())),
-            PerformanceLogEntry.create(
-                "test2/latency",
-                ImmutableMap.of("field1", Optional.empty(), "field2", Optional.empty())),
             PerformanceLogEntry.create(
                 "test3/latency",
                 ImmutableMap.of(
-                    "field1",
+                    "foo", Optional.empty(), "bar", Optional.empty(), "baz", Optional.empty())))
-                    Optional.empty(),
-                    "field2",
-                    Optional.empty(),
-                    "field3",
-                    Optional.empty())))
         .inOrder();
 
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();