Merge pull request #47 from opentracing/bhs/log_kv

Key-value logging

Author: bensigelman

opentracing-api/src/main/java/io/opentracing/Span.java

@@ -13,6 +13,8 @@
  */
 package io.opentracing;
 
+import java.util.Map;
+
 /**
  * Represents an in-flight span in the opentracing system.
  *
@@ -65,25 +67,72 @@ public interface Span extends AutoCloseable {
     Span setTag(String key, Number value);
 
     /**
-     * Add a new log event to the Span, accepting an event name string and an optional structured payload argument.
+     * Log key:value pairs to the Span with the current walltime timestamp.
+     *
+     * <p><strong>CAUTIONARY NOTE:</strong> not all Tracer implementations support key:value log fields end-to-end.
+     * Caveat emptor.
+     *
+     * <p>A contrived example (using Guava, which is not required):
+     * <pre>{@code
+     span.log(
+         ImmutableMap.Builder<String, Object>()
+         .put("event", "soft error")
+         .put("type", "cache timeout")
+         .put("waited.millis", 1500)
+         .build());
+     }</pre>
+     *
+     * @param fields key:value log fields. Tracer implementations should support String, numeric, and boolean values;
+     *               some may also support arbitrary Objects.
+     * @return the Span, for chaining
+     * @see Span#log(String)
+     */
+    Span log(Map<String, ?> fields);
+
+    /**
+     * Like log(Map&lt;String, Object&gt;), but with an explicit timestamp.
      *
-     * If specified, the payload argument may be of any type and arbitrary size, though implementations are not
-     * required to retain all payload arguments (or even all parts of all payload arguments).
+     * <p><strong>CAUTIONARY NOTE:</strong> not all Tracer implementations support key:value log fields end-to-end.
+     * Caveat emptor.
      *
-     * The timestamp of this log event is the current time.
-     **/
-    Span log(String eventName, /* @Nullable */ Object payload);
+     * @param timestampMicroseconds The explicit timestamp for the log record. Must be greater than or equal to the
+     *                              Span's start timestamp.
+     * @param fields key:value log fields. Tracer implementations should support String, numeric, and boolean values;
+     *               some may also support arbitrary Objects.
+     * @return the Span, for chaining
+     * @see Span#log(long, String)
+     */
+    Span log(long timestampMicroseconds, Map<String, ?> fields);
 
     /**
-     * Add a new log event to the Span, accepting an event name string and an optional structured payload argument.
+     * Record an event at the current walltime timestamp.
      *
-     * If specified, the payload argument may be of any type and arbitrary size, though implementations are not
-     * required to retain all payload arguments (or even all parts of all payload arguments).
+     * Shorthand for
      *
-     * The timestamp is specified manually here to represent a past log event.
-     * The timestamp in microseconds in UTC time.
-     **/
-    Span log(long timestampMicroseconds, String eventName, /* @Nullable */ Object payload);
+     * <pre>{@code
+     span.log(Collections.singletonMap("event", event));
+     }</pre>
+     *
+     * @param event the event value; often a stable identifier for a moment in the Span lifecycle
+     * @return the Span, for chaining
+     */
+    Span log(String event);
+
+    /**
+     * Record an event at a specific timestamp.
+     *
+     * Shorthand for
+     *
+     * <pre>{@code
+     span.log(timestampMicroseconds, Collections.singletonMap("event", event));
+     }</pre>
+     *
+     * @param timestampMicroseconds The explicit timestamp for the log record. Must be greater than or equal to the
+     *                              Span's start timestamp.
+     * @param event the event value; often a stable identifier for a moment in the Span lifecycle
+     * @return the Span, for chaining
+     */
+    Span log(long timestampMicroseconds, String event);
 
     /**
      * Sets a baggage item in the Span (and its SpanContext) as a key/value pair.
@@ -111,4 +160,19 @@ public interface Span extends AutoCloseable {
      * @return this Span instance, for chaining
      */
     Span setOperationName(String operationName);
+
+    /**
+     * @deprecated use {@link #log(Map)} like this
+     * {@code span.log(Map.of("event", "timeout"))}
+     * or
+     * {@code span.log(timestampMicroseconds, Map.of("event", "exception", "payload", stackTrace))}
+     **/
+    Span log(String eventName, /* @Nullable */ Object payload);
+    /**
+     * @deprecated use {@link #log(Map)} like this
+     * {@code span.log(timestampMicroseconds, Map.of("event", "timeout"))}
+     * or
+     * {@code span.log(timestampMicroseconds, Map.of("event", "exception", "payload", stackTrace))}
+     **/
+    Span log(long timestampMicroseconds, String eventName, /* @Nullable */ Object payload);
 }

opentracing-api/src/test/java/io/opentracing/PlaygroundTest.java

@@ -15,11 +15,7 @@
 
 import java.time.Duration;
 import java.time.Instant;
-import java.util.ArrayList;
-import java.util.Collections;
-import java.util.HashMap;
-import java.util.List;
-import java.util.Map;
+import java.util.*;
 import java.util.concurrent.TimeUnit;
 
 abstract class AbstractSpan implements Span, SpanContext {
@@ -127,18 +123,46 @@ public final Map<String,String> getBaggage() {
     }
 
     @Override
-    public final Span log(String message, /* @Nullable */ Object payload) {
+    public final Span log(String event) {
+        return log(nowMicros(), event);
+    }
+
+    @Override
+    public final Span log(long timestampMicros, String event) {
+        return log(timestampMicros, Collections.singletonMap("event", event));
+    }
+
+    @Override
+    public final Span log(Map<String, ?> fields) {
+        return log(nowMicros(), fields);
+    }
+
+    @Override
+    public final Span log(long timestampMicros, Map<String, ?> fields) {
+        Instant timestamp = Instant.ofEpochSecond(timestampMicros / 1000000, (timestampMicros % 1000000) * 1000);
+        logs.add(new LogData(timestamp, fields));
+        return this;
+    }
+
+    @Override
+    public final Span log(String event, /* @Nullable */ Object payload) {
         Instant now = Instant.now();
 
         return log(
                 TimeUnit.SECONDS.toMicros(now.getEpochSecond()) + TimeUnit.NANOSECONDS.toMicros(now.getNano()),
-                message,
+                event,
                 payload);
     }
 
     @Override
-    public final Span log(long instantMicroseconds, String message, /* @Nullable */ Object payload) {
-        logs.add(new LogData(start, message, payload));
+    public final Span log(long timestampMicros, String event, /* @Nullable */ Object payload) {
+        Instant timestamp = Instant.ofEpochSecond(timestampMicros / 1000000, (timestampMicros % 1000000) * 1000);
+        Map<String, Object> fields = new HashMap<>();
+        fields.put("event", event);
+        if (payload != null) {
+            fields.put("payload", payload);
+        }
+        logs.add(new LogData(timestamp, fields));
         return this;
     }
 
@@ -148,13 +172,16 @@ public final List<LogData> getLogs() {
 
     final class LogData {
         private final Instant time;
-        private final String message;
-        private final Object payload;
+        private final Map<String, ?> fields;
 
-        LogData(Instant time, String message, Object payload) {
+        LogData(Instant time, Map<String, ?> fields) {
             this.time = time;
-            this.message = message;
-            this.payload = payload;
+            this.fields = fields;
         }
     }
+
+    static long nowMicros() {
+        Instant now = Instant.now();
+        return (now.getEpochSecond() * 1000000) + (now.getNano() / 1000);
+    }
 }

opentracing-impl-java8/src/main/java/io/opentracing/AbstractSpan.java

@@ -39,34 +39,34 @@ public void finish() {}
     public void finish(long finishMicros) {}
 
     @Override
-    public void close() {
-        finish();
-    }
+    public void close() { finish(); }
 
     @Override
-    public Span setTag(String key, String value) {
-        return this;
-    }
+    public Span setTag(String key, String value) { return this; }
 
     @Override
-    public Span setTag(String key, boolean value) {
-        return this;
-    }
+    public Span setTag(String key, boolean value) { return this; }
 
     @Override
-    public Span setTag(String key, Number value) {
-        return this;
-    }
+    public Span setTag(String key, Number value) { return this; }
 
     @Override
-    public Span log(String eventName, Object payload) {
-        return this;
-    }
+    public Span log(Map<String, ?> fields) { return this; }
 
     @Override
-    public Span log(long timestampMicroseconds, String eventName, Object payload) {
-        return this;
-    }
+    public Span log(long timestampMicroseconds, Map<String, ?> fields) { return this; }
+
+    @Override
+    public Span log(String event) { return this; }
+
+    @Override
+    public Span log(long timestampMicroseconds, String event) { return this; }
+
+    @Override
+    public Span log(String eventName, Object payload) { return this; }
+
+    @Override
+    public Span log(long timestampMicroseconds, String eventName, Object payload) { return this; }
 
     @Override
     public Span setBaggageItem(String key, String value) { return this; }
@@ -75,8 +75,6 @@ public Span log(long timestampMicroseconds, String eventName, Object payload) {
     public String getBaggageItem(String key) { return null; }
 
     @Override
-    public Span setOperationName(String operationName) {
-        return this;
-    }
+    public Span setOperationName(String operationName) { return this; }
 
 }