Skip to content

Commit e292611

Browse files
Bennett-LynchBennett-Lynch
authored
Add pretty-format support to LoggingMetricPublisher (#2911)
* Add pretty-format support to LoggingMetricPublisher LoggingMetricPublisher provides a convenient way to emit and inspect metrics via standard logging. The default log format is concise but perhaps difficult to read when looking for particular values. For users that wish to log metrics purely for debugging purposes, we should offer a more readable and user-friendly format.
1 parent ad29dd4 commit e292611

File tree

7 files changed

+369
-6
lines changed

7 files changed

+369
-6
lines changed

‎.changes/next-release/feature-MetricsSPI-9675089.json

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
{
2+
"category": "Metrics",
3+
"contributor": "",
4+
"type": "feature",
5+
"description": "Add pretty-format support to LoggingMetricPublisher"
6+
}

‎core/metrics-spi/pom.xml

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -57,6 +57,16 @@
5757
<artifactId>mockito-core</artifactId>
5858
<scope>test</scope>
5959
</dependency>
60+
<dependency>
61+
<groupId>log4j</groupId>
62+
<artifactId>log4j</artifactId>
63+
<scope>test</scope>
64+
</dependency>
65+
<dependency>
66+
<groupId>org.slf4j</groupId>
67+
<artifactId>slf4j-log4j12</artifactId>
68+
<scope>test</scope>
69+
</dependency>
6070
</dependencies>
6171

6272

‎core/metrics-spi/src/main/java/software/amazon/awssdk/metrics/LoggingMetricPublisher.java

Lines changed: 153 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -15,27 +15,174 @@
1515

1616
package software.amazon.awssdk.metrics;
1717

18+
import static software.amazon.awssdk.utils.StringUtils.repeat;
19+
20+
import java.util.ArrayList;
21+
import java.util.List;
22+
import org.slf4j.event.Level;
1823
import software.amazon.awssdk.annotations.SdkPublicApi;
1924
import software.amazon.awssdk.utils.Logger;
25+
import software.amazon.awssdk.utils.Validate;
2026

2127
/**
22-
* An implementation of {@link MetricPublisher} that writes all published metrics to the logs at the INFO level under the
23-
* {@code software.amazon.awssdk.metrics.LoggingMetricPublisher} namespace.
28+
* An implementation of {@link MetricPublisher} that logs all published metrics under the {@code
29+
* software.amazon.awssdk.metrics.LoggingMetricPublisher} namespace.
30+
* <p>
31+
* {@link LoggingMetricPublisher} can be configured with a {@link Level} to control the log level at which metrics are recorded
32+
* and a {@link Format} to control the format that metrics are printed in.
33+
* <p>
34+
* {@link Format#PLAIN} can be used to print all metrics on a single line. E.g.,
35+
* <pre>
36+
* Metrics published: MetricCollection(name=ApiCall, metrics=[MetricRecord(metric=MarshallingDuration, value=PT0.000202197S),
37+
* MetricRecord(metric=RetryCount, value=0), MetricRecord(metric=ApiCallSuccessful, value=true),
38+
* MetricRecord(metric=OperationName, value=HeadObject), MetricRecord(metric=ApiCallDuration, value=PT0.468369S),
39+
* MetricRecord(metric=CredentialsFetchDuration, value=PT0.000003191S), MetricRecord(metric=ServiceId, value=S3)],
40+
* children=[MetricCollection(name=ApiCallAttempt, metrics=[MetricRecord(metric=SigningDuration, value=PT0.000667268S),
41+
* MetricRecord(metric=ServiceCallDuration, value=PT0.460529977S), MetricRecord(metric=AwsExtendedRequestId,
42+
* value=jY/Co5Ge6WjRYk78kGOYQ4Z/CqUBr6pAAPZtexgOQR3Iqs3QP0OfZz3fDraQiXtmx7eXCZ4sbO0=), MetricRecord(metric=HttpStatusCode,
43+
* value=200), MetricRecord(metric=BackoffDelayDuration, value=PT0S), MetricRecord(metric=AwsRequestId, value=6SJ82R65SADHX098)],
44+
* children=[MetricCollection(name=HttpClient, metrics=[MetricRecord(metric=AvailableConcurrency, value=0),
45+
* MetricRecord(metric=LeasedConcurrency, value=0), MetricRecord(metric=ConcurrencyAcquireDuration, value=PT0.230757S),
46+
* MetricRecord(metric=PendingConcurrencyAcquires, value=0), MetricRecord(metric=MaxConcurrency, value=50),
47+
* MetricRecord(metric=HttpClientName, value=NettyNio)], children=[])])])
48+
* </pre>
49+
* {@link Format#PRETTY} can be used to print metrics over multiple lines in a readable fashion suitable for debugging. E.g.,
50+
* <pre>
51+
* [18e5092e] ApiCall
52+
* [18e5092e] ┌────────────────────────────────────────┐
53+
* [18e5092e] │ MarshallingDuration=PT0.000227427S │
54+
* [18e5092e] │ RetryCount=0 │
55+
* [18e5092e] │ ApiCallSuccessful=true │
56+
* [18e5092e] │ OperationName=HeadObject │
57+
* [18e5092e] │ ApiCallDuration=PT0.541751S │
58+
* [18e5092e] │ CredentialsFetchDuration=PT0.00000306S │
59+
* [18e5092e] │ ServiceId=S3 │
60+
* [18e5092e] └────────────────────────────────────────┘
61+
* [18e5092e] ApiCallAttempt
62+
* [18e5092e] ┌───────────────────────────────────────────────────────────────────────────────────────────────────┐
63+
* [18e5092e] │ SigningDuration=PT0.000974924S │
64+
* [18e5092e] │ ServiceCallDuration=PT0.531462375S │
65+
* [18e5092e] │ AwsExtendedRequestId=eGfwjV3mSwQZQD4YxHLswYguvhQoGcDTkr2jRvpio37a6QmhWd18C8wagC8LkBzzcnOOKoMuiXw= │
66+
* [18e5092e] │ HttpStatusCode=200 │
67+
* [18e5092e] │ BackoffDelayDuration=PT0S │
68+
* [18e5092e] │ AwsRequestId=ED46TP7NN62DDG4Q │
69+
* [18e5092e] └───────────────────────────────────────────────────────────────────────────────────────────────────┘
70+
* [18e5092e] HttpClient
71+
* [18e5092e] ┌────────────────────────────────────────┐
72+
* [18e5092e] │ AvailableConcurrency=0 │
73+
* [18e5092e] │ LeasedConcurrency=0 │
74+
* [18e5092e] │ ConcurrencyAcquireDuration=PT0.235851S │
75+
* [18e5092e] │ PendingConcurrencyAcquires=0 │
76+
* [18e5092e] │ MaxConcurrency=50 │
77+
* [18e5092e] │ HttpClientName=NettyNio │
78+
* [18e5092e] └────────────────────────────────────────┘
79+
* </pre>
80+
* Note that the output format may be subject to small changes in future versions and should not be relied upon as a strict public
81+
* contract.
2482
*/
2583
@SdkPublicApi
2684
public final class LoggingMetricPublisher implements MetricPublisher {
85+
86+
public enum Format {
87+
PLAIN,
88+
PRETTY
89+
}
90+
2791
private static final Logger LOGGER = Logger.loggerFor(LoggingMetricPublisher.class);
92+
private static final Integer PRETTY_INDENT_SIZE = 4;
93+
94+
private final Level logLevel;
95+
private final Format format;
2896

29-
private LoggingMetricPublisher() {
97+
private LoggingMetricPublisher(Level logLevel, Format format) {
98+
this.logLevel = Validate.notNull(logLevel, "logLevel");
99+
this.format = Validate.notNull(format, "format");
30100
}
31101

102+
/**
103+
* Create a {@link LoggingMetricPublisher} with the default configuration of {@link Level#INFO} and {@link Format#PLAIN}.
104+
*/
32105
public static LoggingMetricPublisher create() {
33-
return new LoggingMetricPublisher();
106+
return new LoggingMetricPublisher(Level.INFO, Format.PLAIN);
107+
}
108+
109+
/**
110+
* Create a {@link LoggingMetricPublisher} with a custom {@link Format} and log {@link Level}.
111+
*
112+
* @param logLevel the SLF4J log level to log metrics with
113+
* @param format the format to print the metrics with (see class-level documentation for examples)
114+
*/
115+
public static LoggingMetricPublisher create(Level logLevel, Format format) {
116+
return new LoggingMetricPublisher(logLevel, format);
34117
}
35118

36119
@Override
37-
public void publish(MetricCollection metricCollection) {
38-
LOGGER.info(() -> "Metrics published: " + metricCollection);
120+
public void publish(MetricCollection metrics) {
121+
if (!LOGGER.isLoggingLevelEnabled(logLevel)) {
122+
return;
123+
}
124+
switch (format) {
125+
case PLAIN:
126+
LOGGER.log(logLevel, () -> "Metrics published: " + metrics);
127+
break;
128+
case PRETTY:
129+
String guid = Integer.toHexString(metrics.hashCode());
130+
logPretty(guid, metrics, 0);
131+
break;
132+
default:
133+
throw new IllegalStateException("Unsupported format: " + format);
134+
}
135+
}
136+
137+
private void logPretty(String guid, MetricCollection metrics, int indent) {
138+
// Pre-determine metric key-value-pairs so that we can calculate the necessary padding
139+
List<String> metricValues = new ArrayList<>();
140+
metrics.forEach(m -> {
141+
metricValues.add(String.format("%s=%s", m.metric().name(), m.value()));
142+
});
143+
144+
int maxLen = getMaxLen(metricValues);
145+
146+
// MetricCollection name
147+
LOGGER.log(logLevel, () -> String.format("[%s]%s %s",
148+
guid,
149+
repeat(" ", indent),
150+
metrics.name()));
151+
152+
// Open box
153+
LOGGER.log(logLevel, () -> String.format("[%s]%s ┌%s┐",
154+
guid,
155+
repeat(" ", indent),
156+
repeat("─", maxLen + 2)));
157+
158+
// Metric key-value-pairs
159+
metricValues.forEach(metric -> LOGGER.log(logLevel, () -> {
160+
return String.format("[%s]%s │ %s │",
161+
guid,
162+
repeat(" ", indent),
163+
pad(metric, maxLen));
164+
}));
165+
166+
// Close box
167+
LOGGER.log(logLevel, () -> String.format("[%s]%s └%s┘",
168+
guid,
169+
repeat(" ", indent),
170+
repeat("─", maxLen + 2)));
171+
172+
// Recursively repeat for any children
173+
metrics.children().forEach(child -> logPretty(guid, child, indent + PRETTY_INDENT_SIZE));
174+
}
175+
176+
private static int getMaxLen(List<String> strings) {
177+
int maxLen = 0;
178+
for (String str : strings) {
179+
maxLen = Math.max(maxLen, str.length());
180+
}
181+
return maxLen;
182+
}
183+
184+
private static String pad(String str, int length) {
185+
return str + repeat(" ", length - str.length());
39186
}
40187

41188
@Override

‎core/metrics-spi/src/test/java/software/amazon/awssdk/metrics/LoggingMetricPublisherTest.java

Lines changed: 115 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,115 @@
1+
/*
2+
* Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License").
5+
* You may not use this file except in compliance with the License.
6+
* A copy of the License is located at
7+
*
8+
* http://aws.amazon.com/apache2.0
9+
*
10+
* or in the "license" file accompanying this file. This file is distributed
11+
* on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either
12+
* express or implied. See the License for the specific language governing
13+
* permissions and limitations under the License.
14+
*/
15+
16+
package software.amazon.awssdk.metrics;
17+
18+
import static org.apache.log4j.Level.ALL;
19+
import static org.apache.log4j.Level.DEBUG;
20+
import static org.apache.log4j.Level.INFO;
21+
import static org.assertj.core.api.Assertions.assertThat;
22+
23+
import java.util.Arrays;
24+
import java.util.HashMap;
25+
import java.util.List;
26+
import java.util.Map;
27+
import java.util.stream.Collectors;
28+
import java.util.stream.Stream;
29+
import org.apache.log4j.spi.LoggingEvent;
30+
import org.junit.jupiter.api.Test;
31+
import org.slf4j.event.Level;
32+
import software.amazon.awssdk.metrics.LoggingMetricPublisher.Format;
33+
import software.amazon.awssdk.metrics.internal.DefaultMetricCollection;
34+
import software.amazon.awssdk.metrics.internal.DefaultMetricRecord;
35+
import software.amazon.awssdk.testutils.LogCaptor;
36+
37+
class LoggingMetricPublisherTest {
38+
private static final SdkMetric<Integer> TEST_METRIC =
39+
SdkMetric.create("LoggingMetricPublisherTest", Integer.class, MetricLevel.INFO, MetricCategory.CORE);
40+
41+
@Test
42+
void testDefaultConfiguration() {
43+
MetricCollection qux = metrics("qux");
44+
MetricCollection baz = metrics("baz");
45+
MetricCollection bar = metrics("bar", baz);
46+
MetricCollection foo = metrics("foo", bar, qux);
47+
48+
LoggingMetricPublisher publisher = LoggingMetricPublisher.create();
49+
publisher.publish(foo);
50+
51+
try (LogCaptor logCaptor = new LogCaptor.DefaultLogCaptor(ALL)) {
52+
publisher.publish(foo);
53+
List<LoggingEvent> events = logCaptor.loggedEvents();
54+
assertLogged(events, INFO, "Metrics published: %s", foo);
55+
assertThat(events).isEmpty();
56+
}
57+
}
58+
59+
@Test
60+
void testPrettyFormat() {
61+
MetricCollection qux = metrics("qux");
62+
MetricCollection baz = metrics("baz");
63+
MetricCollection bar = metrics("bar", baz);
64+
MetricCollection foo = metrics("foo", bar, qux);
65+
String guid = Integer.toHexString(foo.hashCode());
66+
67+
LoggingMetricPublisher publisher = LoggingMetricPublisher.create(Level.DEBUG, Format.PRETTY);
68+
publisher.publish(foo);
69+
70+
try (LogCaptor logCaptor = new LogCaptor.DefaultLogCaptor(ALL)) {
71+
publisher.publish(foo);
72+
List<LoggingEvent> events = logCaptor.loggedEvents();
73+
assertLogged(events, DEBUG, "[%s] foo", guid);
74+
assertLogged(events, DEBUG, "[%s] ┌──────────────────────────────┐", guid);
75+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=1 │", guid);
76+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=2 │", guid);
77+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=3 │", guid);
78+
assertLogged(events, DEBUG, "[%s] └──────────────────────────────┘", guid);
79+
assertLogged(events, DEBUG, "[%s] bar", guid);
80+
assertLogged(events, DEBUG, "[%s] ┌──────────────────────────────┐", guid);
81+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=1 │", guid);
82+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=2 │", guid);
83+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=3 │", guid);
84+
assertLogged(events, DEBUG, "[%s] └──────────────────────────────┘", guid);
85+
assertLogged(events, DEBUG, "[%s] baz", guid);
86+
assertLogged(events, DEBUG, "[%s] ┌──────────────────────────────┐", guid);
87+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=1 │", guid);
88+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=2 │", guid);
89+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=3 │", guid);
90+
assertLogged(events, DEBUG, "[%s] └──────────────────────────────┘", guid);
91+
assertLogged(events, DEBUG, "[%s] qux", guid);
92+
assertLogged(events, DEBUG, "[%s] ┌──────────────────────────────┐", guid);
93+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=1 │", guid);
94+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=2 │", guid);
95+
assertLogged(events, DEBUG, "[%s] │ LoggingMetricPublisherTest=3 │", guid);
96+
assertLogged(events, DEBUG, "[%s] └──────────────────────────────┘", guid);
97+
assertThat(events).isEmpty();
98+
}
99+
}
100+
101+
private static MetricCollection metrics(String name, MetricCollection... children) {
102+
Integer[] values = {1, 2, 3};
103+
Map<SdkMetric<?>, List<MetricRecord<?>>> recordMap = new HashMap<>();
104+
List<MetricRecord<?>> records =
105+
Stream.of(values).map(v -> new DefaultMetricRecord<>(TEST_METRIC, v)).collect(Collectors.toList());
106+
recordMap.put(TEST_METRIC, records);
107+
return new DefaultMetricCollection(name, recordMap, Arrays.asList(children));
108+
}
109+
110+
private static void assertLogged(List<LoggingEvent> events, org.apache.log4j.Level level, String message, Object... args) {
111+
LoggingEvent event = events.remove(0);
112+
assertThat(event.getLevel()).isEqualTo(level);
113+
assertThat(event.getMessage()).isEqualTo(String.format(message, args));
114+
}
115+
}

‎core/metrics-spi/src/test/resources/log4j.properties

Lines changed: 33 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,33 @@
1+
#
2+
# Copyright 2010-2019 Amazon.com, Inc. or its affiliates. All Rights Reserved.
3+
#
4+
# Licensed under the Apache License, Version 2.0 (the "License").
5+
# You may not use this file except in compliance with the License.
6+
# A copy of the License is located at
7+
#
8+
# http://aws.amazon.com/apache2.0
9+
#
10+
# or in the "license" file accompanying this file. This file is distributed
11+
# on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either
12+
# express or implied. See the License for the specific language governing
13+
# permissions and limitations under the License.
14+
#
15+
16+
log4j.rootLogger=INFO, A1
17+
log4j.appender.A1=org.apache.log4j.ConsoleAppender
18+
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
19+
20+
# Print the date in ISO 8601 format
21+
log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
22+
23+
# Adjust to see more / less logging
24+
#log4j.logger.com.amazonaws.ec2=DEBUG
25+
26+
# HttpClient 3 Wire Logging
27+
#log4j.logger.httpclient.wire=DEBUG
28+
29+
# HttpClient 4 Wire Logging
30+
#log4j.logger.org.apache.http.wire=DEBUG
31+
#log4j.logger.org.apache.http=DEBUG
32+
#log4j.logger.org.apache.http.wire=WARN
33+
#log4j.logger.software.amazon.awssdk=DEBUG

‎pom.xml

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -423,6 +423,7 @@
423423
<ignoredUsedUndeclaredDependency>org.hamcrest:*</ignoredUsedUndeclaredDependency>
424424
<ignoredUsedUndeclaredDependency>org.testng:testng</ignoredUsedUndeclaredDependency>
425425
<ignoredUsedUndeclaredDependency>org.mockito:*</ignoredUsedUndeclaredDependency>
426+
<ignoredUsedUndeclaredDependency>org.junit.jupiter:*</ignoredUsedUndeclaredDependency>
426427
<ignoredUsedUndeclaredDependency>org.junit.platform:*</ignoredUsedUndeclaredDependency>
427428
<ignoredUsedUndeclaredDependency>org.opentest4j:*</ignoredUsedUndeclaredDependency>
428429

0 commit comments

Comments
 (0)