Reduce performance overhead of ResourceLeakDetector

Motiviation:

The ResourceLeakDetector helps to detect and troubleshoot resource leaks and is often used even in production enviroments with a low level. Because of this its import that we try to keep the overhead as low as overhead. Most of the times no leak is detected (as all is correctly handled) so we should keep the overhead for this case as low as possible.

Modifications:

- Only call getStackTrace() if a leak is reported as it is a very expensive native call. Also handle the filtering and creating of the String in a lazy fashion
- Remove the need to mantain a Queue to store the last access records
- Add benchmark

Result:

Huge decrease of performance overhead.

Before the patch:

Benchmark                                           (recordTimes)   Mode  Cnt     Score     Error  Units
ResourceLeakDetectorRecordBenchmark.record                      8  thrpt   20  4358.367 ± 116.419  ops/s
ResourceLeakDetectorRecordBenchmark.record                     16  thrpt   20  2306.027 ±  55.044  ops/s
ResourceLeakDetectorRecordBenchmark.recordWithHint              8  thrpt   20  4220.979 ± 114.046  ops/s
ResourceLeakDetectorRecordBenchmark.recordWithHint             16  thrpt   20  2250.734 ±  55.352  ops/s

With this patch:

Benchmark                                           (recordTimes)   Mode  Cnt      Score      Error  Units
ResourceLeakDetectorRecordBenchmark.record                      8  thrpt   20  71398.957 ± 2695.925  ops/s
ResourceLeakDetectorRecordBenchmark.record                     16  thrpt   20  38643.963 ± 1446.694  ops/s
ResourceLeakDetectorRecordBenchmark.recordWithHint              8  thrpt   20  71677.882 ± 2923.622  ops/s
ResourceLeakDetectorRecordBenchmark.recordWithHint             16  thrpt   20  38660.176 ± 1467.732  ops/s
This commit is contained in:
Norman Maurer 2017-09-17 07:32:31 -07:00
parent aa8bdb5d6b
commit 3c8c7fc7e9
2 changed files with 242 additions and 108 deletions

View File

@ -23,11 +23,10 @@ import io.netty.util.internal.logging.InternalLoggerFactory;
import java.lang.ref.PhantomReference;
import java.lang.ref.ReferenceQueue;
import java.util.ArrayDeque;
import java.util.Deque;
import java.util.HashSet;
import java.util.Set;
import java.util.concurrent.ConcurrentMap;
import static io.netty.util.internal.EmptyArrays.EMPTY_OBJECTS;
import static io.netty.util.internal.StringUtil.EMPTY_STRING;
import static io.netty.util.internal.StringUtil.NEWLINE;
import static io.netty.util.internal.StringUtil.simpleClassName;
@ -40,7 +39,10 @@ public class ResourceLeakDetector<T> {
private static final String PROP_MAX_RECORDS = "io.netty.leakDetection.maxRecords";
private static final int DEFAULT_MAX_RECORDS = 4;
private static final String PROP_MAX_SAMPLED_RECORDS = "io.netty.leakDetection.maxSampledRecords";
private static final int MAX_RECORDS;
private static final int MAX_SAMPLED_RECORDS;
/**
* Represents the level of resource leak detection.
@ -109,11 +111,14 @@ public class ResourceLeakDetector<T> {
Level level = Level.parseLevel(levelStr);
MAX_RECORDS = SystemPropertyUtil.getInt(PROP_MAX_RECORDS, DEFAULT_MAX_RECORDS);
long maxRecordsSampled = SystemPropertyUtil.getLong(PROP_MAX_SAMPLED_RECORDS, MAX_RECORDS * 10L);
MAX_SAMPLED_RECORDS = Math.max((int) Math.min(Integer.MAX_VALUE, maxRecordsSampled), MAX_RECORDS);
ResourceLeakDetector.level = level;
if (logger.isDebugEnabled()) {
logger.debug("-D{}: {}", PROP_LEVEL, level.name().toLowerCase());
logger.debug("-D{}: {}", PROP_MAX_RECORDS, MAX_RECORDS);
logger.debug("-D{}: {}", PROP_MAX_SAMPLED_RECORDS, MAX_SAMPLED_RECORDS);
}
}
@ -245,27 +250,29 @@ public class ResourceLeakDetector<T> {
if (level.ordinal() < Level.PARANOID.ordinal()) {
if ((PlatformDependent.threadLocalRandom().nextInt(samplingInterval)) == 0) {
reportLeak(level);
reportLeak();
return new DefaultResourceLeak(obj);
} else {
return null;
}
} else {
reportLeak(level);
return new DefaultResourceLeak(obj);
return null;
}
reportLeak();
return new DefaultResourceLeak(obj);
}
private void clearRefQueue() {
for (;;) {
@SuppressWarnings("unchecked")
DefaultResourceLeak ref = (DefaultResourceLeak) refQueue.poll();
if (ref == null) {
break;
}
ref.close();
}
}
private void reportLeak(Level level) {
private void reportLeak() {
if (!logger.isErrorEnabled()) {
for (;;) {
@SuppressWarnings("unchecked")
DefaultResourceLeak ref = (DefaultResourceLeak) refQueue.poll();
if (ref == null) {
break;
}
ref.close();
}
clearRefQueue();
return;
}
@ -328,11 +335,14 @@ public class ResourceLeakDetector<T> {
@SuppressWarnings("deprecation")
private final class DefaultResourceLeak extends PhantomReference<Object> implements ResourceLeakTracker<T>,
ResourceLeak {
private final String creationRecord;
private final Deque<String> lastRecords;
private final int trackedHash;
private final Record head;
private int removedRecords;
// This will be updated once a new Record will be created and added
private Record tail;
private final int trackedHash;
private int numRecords;
private int droppedRecords;
DefaultResourceLeak(Object referent) {
super(referent, refQueue);
@ -343,41 +353,42 @@ public class ResourceLeakDetector<T> {
// It's important that we not store a reference to the referent as this would disallow it from
// be collected via the PhantomReference.
trackedHash = System.identityHashCode(referent);
Level level = getLevel();
if (level.ordinal() >= Level.ADVANCED.ordinal()) {
creationRecord = newRecord(null, 3);
lastRecords = new ArrayDeque<String>();
} else {
creationRecord = null;
lastRecords = null;
}
head = tail = getLevel().ordinal() >= Level.ADVANCED.ordinal() ? new Record() : null;
allLeaks.put(this, LeakEntry.INSTANCE);
}
@Override
public void record() {
record0(null, 3);
record0(null);
}
@Override
public void record(Object hint) {
record0(hint, 3);
record0(hint);
}
private void record0(Object hint, int recordsToSkip) {
private void record0(Object hint) {
// Check MAX_RECORDS > 0 here to avoid similar check before remove from and add to lastRecords
if (creationRecord != null && MAX_RECORDS > 0) {
String value = newRecord(hint, recordsToSkip);
if (head != null && MAX_RECORDS > 0) {
synchronized (head) {
if (tail == null) {
// already closed
return;
}
synchronized (lastRecords) {
int size = lastRecords.size();
if (size == 0 || !lastRecords.getLast().equals(value)) {
if (size >= MAX_RECORDS) {
lastRecords.removeFirst();
++removedRecords;
}
lastRecords.add(value);
Record record = hint == null ? new Record() : new Record(hint);
tail.next = record;
tail = record;
// Enforce a limit so our linked-list not grows too large and cause a GC storm later on when we
// unlink it. The reason why we choose a different limit to MAX_RECORDS is that we will not handle
// duplications here as its very expensive. We will filter these out when we actually
// detected a leak.
if (numRecords == MAX_SAMPLED_RECORDS) {
head.next = head.next.next;
droppedRecords++;
} else {
numRecords++;
}
}
}
@ -386,7 +397,21 @@ public class ResourceLeakDetector<T> {
@Override
public boolean close() {
// Use the ConcurrentMap remove method, which avoids allocating an iterator.
return allLeaks.remove(this, LeakEntry.INSTANCE);
if (allLeaks.remove(this, LeakEntry.INSTANCE)) {
// Call clear so the reference is not even enqueued.
clear();
if (head != null) {
synchronized (head) {
// Allow to GC all the records.
head.next = null;
numRecords = 0;
tail = null;
}
}
return true;
}
return false;
}
@Override
@ -403,39 +428,64 @@ public class ResourceLeakDetector<T> {
@Override
public String toString() {
if (creationRecord == null) {
if (head == null) {
return EMPTY_STRING;
}
final Object[] array;
final int removedRecords;
if (lastRecords != null) {
synchronized (lastRecords) {
array = lastRecords.toArray();
removedRecords = this.removedRecords;
final String creationRecord;
final String[] array;
int idx = 0;
String last = null;
final int dropped;
synchronized (head) {
if (tail == null) {
// Already closed
return EMPTY_STRING;
}
dropped = droppedRecords;
creationRecord = head.toString();
array = new String[numRecords];
Record record = head.next;
while (record != null) {
String recordStr = record.toString();
if (last == null || !last.equals(recordStr)) {
array[idx ++] = recordStr;
last = recordStr;
}
record = record.next;
}
} else {
removedRecords = 0;
array = EMPTY_OBJECTS;
}
int removed = idx > MAX_RECORDS ? idx - MAX_RECORDS : 0;
StringBuilder buf = new StringBuilder(16384).append(NEWLINE);
if (removedRecords > 0) {
if (removed > 0) {
buf.append("WARNING: ")
.append(removedRecords)
.append(" leak records were discarded because the leak record count is limited to ")
.append(MAX_RECORDS)
.append(". Use system property ")
.append(PROP_MAX_RECORDS)
.append(" to increase the limit.")
.append(NEWLINE);
.append(removed)
.append(" leak records were discarded because the leak record count is limited to ")
.append(MAX_RECORDS)
.append(". Use system property ")
.append(PROP_MAX_RECORDS)
.append(" to increase the limit.")
.append(NEWLINE);
}
if (dropped > 0) {
buf.append(dropped)
.append(" leak records were not sampled because the leak record sample count is limited to ")
.append(MAX_SAMPLED_RECORDS)
.append(". Use system property ")
.append(PROP_MAX_SAMPLED_RECORDS)
.append(" to increase the limit.")
.append(NEWLINE);
}
buf.append("Recent access records: ")
.append(array.length)
.append(NEWLINE);
if (array.length > 0) {
for (int i = array.length - 1; i >= 0; i --) {
int records = idx - removed;
buf.append("Recent access records: ").append(records).append(NEWLINE);
if (records > 0) {
// The array may not be completely filled so we need to take this into account.
for (int i = records - 1; i >= 0; i --) {
buf.append('#')
.append(i + 1)
.append(':')
@ -453,54 +503,52 @@ public class ResourceLeakDetector<T> {
}
}
private static final String[] STACK_TRACE_ELEMENT_EXCLUSIONS = {
"io.netty.util.ReferenceCountUtil.touch(",
"io.netty.buffer.AdvancedLeakAwareByteBuf.touch(",
"io.netty.buffer.AbstractByteBufAllocator.toLeakAwareBuffer(",
"io.netty.buffer.AdvancedLeakAwareByteBuf.recordLeakNonRefCountingOperation("
};
private static final class Record extends Throwable {
static String newRecord(Object hint, int recordsToSkip) {
StringBuilder buf = new StringBuilder(4096);
// Append the hint first if available.
if (hint != null) {
buf.append("\tHint: ");
// Prefer a hint string to a simple string form.
if (hint instanceof ResourceLeakHint) {
buf.append(((ResourceLeakHint) hint).toHintString());
} else {
buf.append(hint);
}
buf.append(NEWLINE);
private static final Set<String> STACK_TRACE_ELEMENT_EXCLUSIONS = new HashSet<String>();
static {
STACK_TRACE_ELEMENT_EXCLUSIONS.add("io.netty.util.ReferenceCountUtil.touch");
STACK_TRACE_ELEMENT_EXCLUSIONS.add("io.netty.buffer.AdvancedLeakAwareByteBuf.touch");
STACK_TRACE_ELEMENT_EXCLUSIONS.add("io.netty.buffer.AbstractByteBufAllocator.toLeakAwareBuffer");
STACK_TRACE_ELEMENT_EXCLUSIONS.add(
"io.netty.buffer.AdvancedLeakAwareByteBuf.recordLeakNonRefCountingOperation");
}
// Append the stack trace.
StackTraceElement[] array = new Throwable().getStackTrace();
for (StackTraceElement e: array) {
if (recordsToSkip > 0) {
recordsToSkip --;
} else {
String estr = e.toString();
private final String hintString;
Record next;
Record(Object hint) {
// This needs to be generated even if toString() is never called as it may change later on.
hintString = hint instanceof ResourceLeakHint ? ((ResourceLeakHint) hint).toHintString() : hint.toString();
}
Record() {
hintString = null;
}
@Override
public String toString() {
StringBuilder buf = new StringBuilder(4096);
if (hintString != null) {
buf.append("\tHint: ").append(hintString).append(NEWLINE);
}
// Append the stack trace.
StackTraceElement[] array = getStackTrace();
// Skip the first three elements.
for (int i = 3; i < array.length; i++) {
StackTraceElement element = array[i];
// Strip the noisy stack trace elements.
boolean excluded = false;
for (String exclusion: STACK_TRACE_ELEMENT_EXCLUSIONS) {
if (estr.startsWith(exclusion)) {
excluded = true;
break;
}
}
if (!excluded) {
buf.append('\t');
buf.append(estr);
buf.append(NEWLINE);
if (STACK_TRACE_ELEMENT_EXCLUSIONS.contains(element.getClassName() + '.' + element.getMethodName())) {
continue;
}
buf.append('\t');
buf.append(element.toString());
buf.append(NEWLINE);
}
return buf.toString();
}
return buf.toString();
}
private static final class LeakEntry {

View File

@ -0,0 +1,86 @@
/*
* Copyright 2017 The Netty Project
*
* The Netty Project licenses this file to you under the Apache License,
* version 2.0 (the "License"); you may not use this file except in compliance
* with the License. You may obtain a copy of the License at:
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
* WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
* License for the specific language governing permissions and limitations
* under the License.
*/
package io.netty.microbench.util;
import io.netty.util.ResourceLeakDetector;
import io.netty.util.ResourceLeakHint;
import io.netty.util.ResourceLeakTracker;
import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.Level;
import org.openjdk.jmh.annotations.Param;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.TearDown;
public class ResourceLeakDetectorRecordBenchmark extends AbstractMicrobenchmark {
private static final Object TRACKED = new Object();
private static final ResourceLeakHint HINT = new ResourceLeakHint() {
@Override
public String toHintString() {
return "BenchmarkHint";
}
};
@Param({ "8", "16" })
private int recordTimes;
private ResourceLeakDetector.Level level;
ResourceLeakDetector<Object> detector = new ResourceLeakDetector<Object>(
Object.class, 1, Integer.MAX_VALUE) {
@Override
protected void reportTracedLeak(String resourceType, String records) {
// noop
}
@Override
protected void reportUntracedLeak(String resourceType) {
// noop
}
@Override
protected void reportInstancesLeak(String resourceType) {
// noop
}
};
@Setup(Level.Trial)
public void setup() {
level = ResourceLeakDetector.getLevel();
ResourceLeakDetector.setLevel(ResourceLeakDetector.Level.PARANOID);
}
@TearDown(Level.Trial)
public void teardown() {
ResourceLeakDetector.setLevel(level);
}
@Benchmark
public boolean record() {
ResourceLeakTracker<Object> tracker = detector.track(TRACKED);
for (int i = 0 ; i < recordTimes; i++) {
tracker.record();
}
return tracker.close(TRACKED);
}
@Benchmark
public boolean recordWithHint() {
ResourceLeakTracker<Object> tracker = detector.track(TRACKED);
for (int i = 0 ; i < recordTimes; i++) {
tracker.record(HINT);
}
return tracker.close(TRACKED);
}
}