Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

4.1 dev slf4j metric attributes #1275

Merged
merged 3 commits into from
Feb 25, 2018
Merged

4.1 dev slf4j metric attributes #1275

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
3968e0e
Support for disabledMetricAttributes in Slf4jReporter
fabienrenaud Feb 21, 2018
1b39f3f
Tests for metric attribute filter in Slf4jReporter
fabienrenaud Feb 21, 2018
d3ccf74
Slf4jReporter: addressed PR feedback
fabienrenaud Feb 23, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
234 changes: 158 additions & 76 deletions metrics-core/src/main/java/com/codahale/metrics/Slf4jReporter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,15 @@
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;

import java.util.Collections;
import java.util.Map.Entry;
import java.util.Set;
import java.util.SortedMap;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
import java.util.function.Supplier;

import static com.codahale.metrics.MetricAttribute.*;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please don't use star imports, in the codebase we tend to use direct imports.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

fixed.


/**
* A reporter class for logging metrics values to a SLF4J {@link Logger} periodically, similar to
Expand Down Expand Up @@ -44,6 +49,7 @@ public static class Builder {
private MetricFilter filter;
private ScheduledExecutorService executor;
private boolean shutdownExecutorOnStop;
private Set<MetricAttribute> disabledMetricAttributes;

private Builder(MetricRegistry registry) {
this.registry = registry;
Expand All @@ -56,6 +62,7 @@ private Builder(MetricRegistry registry) {
this.loggingLevel = LoggingLevel.INFO;
this.executor = null;
this.shutdownExecutorOnStop = true;
this.disabledMetricAttributes = Collections.emptySet();
}

/**
Expand Down Expand Up @@ -161,6 +168,18 @@ public Builder withLoggingLevel(LoggingLevel loggingLevel) {
return this;
}

/**
* Don't report the passed metric attributes for all metrics (e.g. "p999", "stddev" or "m15").
* See {@link MetricAttribute}.
*
* @param disabledMetricAttributes a {@link MetricFilter}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

s/MetricFilter/a set of MetricAttribute

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

fixed. fixed GraphiteReporter as well.

* @return {@code this}
*/
public Builder disabledMetricAttributes(Set<MetricAttribute> disabledMetricAttributes) {
this.disabledMetricAttributes = disabledMetricAttributes;
return this;
}

/**
* Builds a {@link Slf4jReporter} with the given properties.
*
Expand All @@ -186,13 +205,14 @@ public Slf4jReporter build() {
loggerProxy = new DebugLoggerProxy(logger);
break;
}
return new Slf4jReporter(registry, loggerProxy, marker, prefix, rateUnit, durationUnit, filter, executor, shutdownExecutorOnStop);
return new Slf4jReporter(registry, loggerProxy, marker, prefix, rateUnit, durationUnit, filter, executor, shutdownExecutorOnStop, disabledMetricAttributes);
}
}

private final LoggerProxy loggerProxy;
private final Marker marker;
private final String prefix;
private final ThreadLocal<StringBuilder> threadLocalStringBuilder = ThreadLocal.withInitial(StringBuilder::new);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I feel that using a ThreadLocal is a premature optimization. It's not clear for me that it will provide a big performance boost over allocating a new StringBuilder. Also, using ThreadLocal can cause strange classloader leaks if one fail to clear a reference to it.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

removed ThreadLocal. StringBuilder has to be a local variable to the report method since there is no guarantee the method won't be executed in parallel.


private Slf4jReporter(MetricRegistry registry,
LoggerProxy loggerProxy,
Expand All @@ -202,8 +222,9 @@ private Slf4jReporter(MetricRegistry registry,
TimeUnit durationUnit,
MetricFilter filter,
ScheduledExecutorService executor,
boolean shutdownExecutorOnStop) {
super(registry, "logger-reporter", filter, rateUnit, durationUnit, executor, shutdownExecutorOnStop);
boolean shutdownExecutorOnStop,
Set<MetricAttribute> disabledMetricAttributes) {
super(registry, "logger-reporter", filter, rateUnit, durationUnit, executor, shutdownExecutorOnStop, disabledMetricAttributes);
this.loggerProxy = loggerProxy;
this.marker = marker;
this.prefix = prefix;
Expand All @@ -217,94 +238,155 @@ public void report(SortedMap<String, Gauge> gauges,
SortedMap<String, Meter> meters,
SortedMap<String, Timer> timers) {
if (loggerProxy.isEnabled(marker)) {
StringBuilder b = threadLocalStringBuilder.get();
for (Entry<String, Gauge> entry : gauges.entrySet()) {
logGauge(entry.getKey(), entry.getValue());
logGauge(b, entry.getKey(), entry.getValue());
}

for (Entry<String, Counter> entry : counters.entrySet()) {
logCounter(entry.getKey(), entry.getValue());
if (!getDisabledMetricAttributes().contains(COUNT)) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

count is not used to filtering counters. It's used only to filter the count attribute of histograms, meters, and timers. Users can filter counters by MetricFilter.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

removed if.

for (Entry<String, Counter> entry : counters.entrySet()) {
logCounter(b, entry.getKey(), entry.getValue());
}
}

for (Entry<String, Histogram> entry : histograms.entrySet()) {
logHistogram(entry.getKey(), entry.getValue());
logHistogram(b, entry.getKey(), entry.getValue());
}

for (Entry<String, Meter> entry : meters.entrySet()) {
logMeter(entry.getKey(), entry.getValue());
logMeter(b, entry.getKey(), entry.getValue());
}

for (Entry<String, Timer> entry : timers.entrySet()) {
logTimer(entry.getKey(), entry.getValue());
logTimer(b, entry.getKey(), entry.getValue());
}
}
}

private void logTimer(String name, Timer timer) {
private void logTimer(StringBuilder b, String name, Timer timer) {
final Snapshot snapshot = timer.getSnapshot();
loggerProxy.log(marker,
"type={}, name={}, count={}, min={}, max={}, mean={}, stddev={}, median={}, " +
"p75={}, p95={}, p98={}, p99={}, p999={}, mean_rate={}, m1={}, m5={}, " +
"m15={}, rate_unit={}, duration_unit={}",
"TIMER",
prefix(name),
timer.getCount(),
convertDuration(snapshot.getMin()),
convertDuration(snapshot.getMax()),
convertDuration(snapshot.getMean()),
convertDuration(snapshot.getStdDev()),
convertDuration(snapshot.getMedian()),
convertDuration(snapshot.get75thPercentile()),
convertDuration(snapshot.get95thPercentile()),
convertDuration(snapshot.get98thPercentile()),
convertDuration(snapshot.get99thPercentile()),
convertDuration(snapshot.get999thPercentile()),
convertRate(timer.getMeanRate()),
convertRate(timer.getOneMinuteRate()),
convertRate(timer.getFiveMinuteRate()),
convertRate(timer.getFifteenMinuteRate()),
getRateUnit(),
getDurationUnit());
b.setLength(0);
b.append("type=TIMER");
append(b, "name", prefix(name));
appendCountIfEnabled(b, timer);
appendLongDurationIfEnabled(b, MIN, snapshot::getMin);
appendLongDurationIfEnabled(b, MAX, snapshot::getMax);
appendDoubleDurationIfEnabled(b, MEAN, snapshot::getMean);
appendDoubleDurationIfEnabled(b, STDDEV, snapshot::getStdDev);
appendDoubleDurationIfEnabled(b, P50, snapshot::getMedian);
appendDoubleDurationIfEnabled(b, P75, snapshot::get75thPercentile);
appendDoubleDurationIfEnabled(b, P95, snapshot::get95thPercentile);
appendDoubleDurationIfEnabled(b, P98, snapshot::get98thPercentile);
appendDoubleDurationIfEnabled(b, P99, snapshot::get99thPercentile);
appendDoubleDurationIfEnabled(b, P999, snapshot::get999thPercentile);
appendMetered(b, timer);
append(b, "rate_unit", getRateUnit());
append(b, "duration_unit", getDurationUnit());
loggerProxy.log(marker, b.toString());
}

private void logMeter(String name, Meter meter) {
loggerProxy.log(marker,
"type={}, name={}, count={}, mean_rate={}, m1={}, m5={}, m15={}, rate_unit={}",
"METER",
prefix(name),
meter.getCount(),
convertRate(meter.getMeanRate()),
convertRate(meter.getOneMinuteRate()),
convertRate(meter.getFiveMinuteRate()),
convertRate(meter.getFifteenMinuteRate()),
getRateUnit());
private void logMeter(StringBuilder b, String name, Meter meter) {
b.setLength(0);
b.append("type=METER");
append(b, "name", prefix(name));
appendCountIfEnabled(b, meter);
appendMetered(b, meter);
append(b, "rate_unit", getRateUnit());
loggerProxy.log(marker, b.toString());
}

private void logHistogram(String name, Histogram histogram) {
private void logHistogram(StringBuilder b, String name, Histogram histogram) {
final Snapshot snapshot = histogram.getSnapshot();
loggerProxy.log(marker,
"type={}, name={}, count={}, min={}, max={}, mean={}, stddev={}, " +
"median={}, p75={}, p95={}, p98={}, p99={}, p999={}",
"HISTOGRAM",
prefix(name),
histogram.getCount(),
snapshot.getMin(),
snapshot.getMax(),
snapshot.getMean(),
snapshot.getStdDev(),
snapshot.getMedian(),
snapshot.get75thPercentile(),
snapshot.get95thPercentile(),
snapshot.get98thPercentile(),
snapshot.get99thPercentile(),
snapshot.get999thPercentile());
b.setLength(0);
b.append("type=HISTOGRAM");
append(b, "name", prefix(name));
appendCountIfEnabled(b, histogram);
appendLongIfEnabled(b, MIN, snapshot::getMin);
appendLongIfEnabled(b, MAX, snapshot::getMax);
appendDoubleIfEnabled(b, MEAN, snapshot::getMean);
appendDoubleIfEnabled(b, STDDEV, snapshot::getStdDev);
appendDoubleIfEnabled(b, P50, snapshot::getMedian);
appendDoubleIfEnabled(b, P75, snapshot::get75thPercentile);
appendDoubleIfEnabled(b, P95, snapshot::get95thPercentile);
appendDoubleIfEnabled(b, P98, snapshot::get98thPercentile);
appendDoubleIfEnabled(b, P99, snapshot::get99thPercentile);
appendDoubleIfEnabled(b, P999, snapshot::get999thPercentile);
loggerProxy.log(marker, b.toString());
}

private void logCounter(StringBuilder b, String name, Counter counter) {
b.setLength(0);
b.append("type=COUNTER");
append(b, "name", prefix(name));
append(b, COUNT.getCode(), counter.getCount());
loggerProxy.log(marker, b.toString());
}

private void logGauge(StringBuilder b, String name, Gauge<?> gauge) {
b.setLength(0);
b.append("type=GAUGE");
append(b, "name", prefix(name));
append(b, "value", gauge.getValue());
loggerProxy.log(marker, b.toString());
}

private void appendLongDurationIfEnabled(StringBuilder b, MetricAttribute metricAttribute, Supplier<Long> durationSupplier) {
if (!getDisabledMetricAttributes().contains(metricAttribute)) {
append(b, metricAttribute.getCode(), convertDuration(durationSupplier.get()));
}
}

private void appendDoubleDurationIfEnabled(StringBuilder b, MetricAttribute metricAttribute, Supplier<Double> durationSupplier) {
if (!getDisabledMetricAttributes().contains(metricAttribute)) {
append(b, metricAttribute.getCode(), convertDuration(durationSupplier.get()));
}
}

private void appendLongIfEnabled(StringBuilder b, MetricAttribute metricAttribute, Supplier<Long> durationSupplier) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

renamed durationSupplier here since this isn't a duration.

if (!getDisabledMetricAttributes().contains(metricAttribute)) {
append(b, metricAttribute.getCode(), durationSupplier.get());
}
}

private void appendDoubleIfEnabled(StringBuilder b, MetricAttribute metricAttribute, Supplier<Double> durationSupplier) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ditto

if (!getDisabledMetricAttributes().contains(metricAttribute)) {
append(b, metricAttribute.getCode(), durationSupplier.get());
}
}

private void appendCountIfEnabled(StringBuilder b, Counting counting) {
if (!getDisabledMetricAttributes().contains(COUNT)) {
append(b, COUNT.getCode(), counting.getCount());
}
}

private void appendMetered(StringBuilder b, Metered meter) {
appendRateIfEnabled(b, M1_RATE, meter::getOneMinuteRate);
appendRateIfEnabled(b, M5_RATE, meter::getFiveMinuteRate);
appendRateIfEnabled(b, M15_RATE, meter::getFifteenMinuteRate);
appendRateIfEnabled(b, MEAN_RATE, meter::getMeanRate);
}

private void appendRateIfEnabled(StringBuilder b, MetricAttribute metricAttribute, Supplier<Double> rateSupplier) {
if (!getDisabledMetricAttributes().contains(metricAttribute)) {
append(b, metricAttribute.getCode(), convertRate(rateSupplier.get()));
}
}

private void append(StringBuilder b, String key, long value) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It seems to me that perfomance benefits of not conveting primtives to wrappers are slim to have 4 apennd methods. I think one method accepting an Object should be enough, especially considering that in most cases we use Supplier which forces auto-boxing.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think they are worth keeping:

  • they are very simple methods, easy to read, understand, change. no hidden code complexity here.
  • convertDuration and convertRate return double so only having an append(...,Object) could cause extra auto-boxing
  • the JVM can likely optimize primitive -> box(primitive) -> primitive call chains
  • and yes, StringBuilder.append(long) is slightly more efficient than StringBuilder.append(Object) called with a Long (unless the JVM un-erases types for some core classes? -- Hotspot JVM does some surprising optimizations some times :) ).

I can remove them if you feel strongly about it but now that the code is there, I think it's worth keeping.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair enough

b.append(", ").append(key).append('=').append(value);
}

private void append(StringBuilder b, String key, double value) {
b.append(", ").append(key).append('=').append(value);
}

private void logCounter(String name, Counter counter) {
loggerProxy.log(marker, "type={}, name={}, count={}", "COUNTER", prefix(name), counter.getCount());
private void append(StringBuilder b, String key, String value) {
b.append(", ").append(key).append('=').append(value);
}

private void logGauge(String name, Gauge<?> gauge) {
loggerProxy.log(marker, "type={}, name={}, value={}", "GAUGE", prefix(name), gauge.getValue());
private void append(StringBuilder b, String key, Object value) {
b.append(", ").append(key).append('=').append(value);
}

@Override
Expand All @@ -324,7 +406,7 @@ public LoggerProxy(Logger logger) {
this.logger = logger;
}

abstract void log(Marker marker, String format, Object... arguments);
abstract void log(Marker marker, String format);

abstract boolean isEnabled(Marker marker);
}
Expand All @@ -336,8 +418,8 @@ public DebugLoggerProxy(Logger logger) {
}

@Override
public void log(Marker marker, String format, Object... arguments) {
logger.debug(marker, format, arguments);
public void log(Marker marker, String format) {
logger.debug(marker, format);
}

@Override
Expand All @@ -353,8 +435,8 @@ public TraceLoggerProxy(Logger logger) {
}

@Override
public void log(Marker marker, String format, Object... arguments) {
logger.trace(marker, format, arguments);
public void log(Marker marker, String format) {
logger.trace(marker, format);
}

@Override
Expand All @@ -370,8 +452,8 @@ public InfoLoggerProxy(Logger logger) {
}

@Override
public void log(Marker marker, String format, Object... arguments) {
logger.info(marker, format, arguments);
public void log(Marker marker, String format) {
logger.info(marker, format);
}

@Override
Expand All @@ -387,8 +469,8 @@ public WarnLoggerProxy(Logger logger) {
}

@Override
public void log(Marker marker, String format, Object... arguments) {
logger.warn(marker, format, arguments);
public void log(Marker marker, String format) {
logger.warn(marker, format);
}

@Override
Expand All @@ -404,8 +486,8 @@ public ErrorLoggerProxy(Logger logger) {
}

@Override
public void log(Marker marker, String format, Object... arguments) {
logger.error(marker, format, arguments);
public void log(Marker marker, String format) {
logger.error(marker, format);
}

@Override
Expand Down