diff --git a/changelog/@unreleased/pr-22.v2.yml b/changelog/@unreleased/pr-22.v2.yml new file mode 100644 index 0000000..fd697f0 --- /dev/null +++ b/changelog/@unreleased/pr-22.v2.yml @@ -0,0 +1,5 @@ +type: improvement +improvement: + description: Formatted trace logs include tracing tags + links: + - https://github.com/palantir/witchcraft-java-logging/pull/22 diff --git a/witchcraft-logging-formatting/src/main/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatter.java b/witchcraft-logging-formatting/src/main/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatter.java index 8d3110b..8424a30 100644 --- a/witchcraft-logging-formatting/src/main/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatter.java +++ b/witchcraft-logging-formatting/src/main/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatter.java @@ -16,8 +16,10 @@ package com.palantir.witchcraft.java.logging.format; +import com.palantir.witchcraft.api.logging.Span; import com.palantir.witchcraft.api.logging.TraceLogV1; import java.time.format.DateTimeFormatter; +import java.util.Map; final class TraceLogFormatter { private TraceLogFormatter() {} @@ -26,15 +28,21 @@ static String format(TraceLogV1 trace) { return Formatting.withStringBuilder(buffer -> { buffer.append('['); DateTimeFormatter.ISO_INSTANT.formatTo(trace.getTime(), buffer); - buffer.append("] traceId: ") - .append(trace.getSpan().getTraceId()) - .append(" id: ") - .append(trace.getSpan().getId()) - .append(" name: ") - .append(trace.getSpan().getName()) - .append(" duration: ") - .append(trace.getSpan().getDuration().longValue()) - .append(" microseconds"); + Span span = trace.getSpan(); + buffer.append("] trace: ") + .append(span.getTraceId()) + .append(", span: ") + .append(span.getId()) + .append(", name: ") + .append(span.getName()) + .append(", duration: ") + .append(span.getDuration().longValue()) + .append(" µs"); + Map tags = span.getTags(); + if (!tags.isEmpty()) { + buffer.append(' '); + Formatting.niceMap(tags, buffer); + } }); } } diff --git a/witchcraft-logging-formatting/src/test/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatterTest.java b/witchcraft-logging-formatting/src/test/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatterTest.java index a1f3a98..e4b7ffd 100644 --- a/witchcraft-logging-formatting/src/test/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatterTest.java +++ b/witchcraft-logging-formatting/src/test/java/com/palantir/witchcraft/java/logging/format/TraceLogFormatterTest.java @@ -40,7 +40,26 @@ void formats_correctly() { .build()); assertThat(formatted) - .isEqualTo( - "[2019-12-25T01:02:03Z] traceId: abdefghijklmno id: id name: name duration: 31 microseconds"); + .isEqualTo("[2019-12-25T01:02:03Z] trace: abdefghijklmno, span: id, name: name, duration: 31 µs"); + } + + @Test + void formats_tags_correctly() { + String formatted = TraceLogFormatter.format(TraceLogV1.builder() + .type("trace.1") + .time(TestData.XMAS_2019) + .span(Span.builder() + .traceId("abdefghijklmno") + .id("id") + .name("name") + .timestamp(SafeLong.of(999)) + .duration(SafeLong.of(31)) + .tags("tagName", "tagValue") + .build()) + .build()); + + assertThat(formatted) + .isEqualTo("[2019-12-25T01:02:03Z] trace: abdefghijklmno, span: id, " + + "name: name, duration: 31 µs (tagName: tagValue)"); } } diff --git a/witchcraft-logging-idea/src/test/java/com/palantir/witchcraft/java/logging/idea/WitchcraftLogFormatFilterTest.java b/witchcraft-logging-idea/src/test/java/com/palantir/witchcraft/java/logging/idea/WitchcraftLogFormatFilterTest.java index 3dad2eb..78569b5 100644 --- a/witchcraft-logging-idea/src/test/java/com/palantir/witchcraft/java/logging/idea/WitchcraftLogFormatFilterTest.java +++ b/witchcraft-logging-idea/src/test/java/com/palantir/witchcraft/java/logging/idea/WitchcraftLogFormatFilterTest.java @@ -69,8 +69,8 @@ public final class WitchcraftLogFormatFilterTest { + "\"name\":\"config-reload\",\"timestamp\":1558716040949000,\"duration\":618," + "\"annotations\":[{\"timestamp\":1558716040949000,\"value\":\"lc\"," + "\"endpoint\":{\"serviceName\":\"my-service\",\"ipv4\":\"10.193.122.103\"}}]}}"; - private static final String TRACE_FORMATTED = "[2019-05-24T16:40:40.950Z] traceId: 2250486695021e19 " - + "id: c11b9a31555b7035 name: config-reload duration: 618 microseconds"; + private static final String TRACE_FORMATTED = "[2019-05-24T16:40:40.950Z] trace: 2250486695021e19, " + + "span: c11b9a31555b7035, name: config-reload, duration: 618 µs"; private static final String NEWLINE = "\n";