From 0867f99be179be8ea48c307f784cd0957f774dd1 Mon Sep 17 00:00:00 2001 From: Chris Vest Date: Fri, 5 Mar 2021 16:32:10 +0100 Subject: [PATCH] Add LifecycleTracer to help debug lifecycle/ownership issues Motivation: With reference counting it can be difficult to keep track of ownership and references. When bugs arise in this area, it's good to get help from some tooling. Modification: Add a LifecycleTracer which records lifecycle changes. This information can be attached to any lifecycle/ownership exceptions as suppressed exceptions. The tracing is off by default, unless assertions are enabled. Result: It's now easier to debug reference counting/lifecycle/ownership issues. --- .../io/netty/buffer/api/LifecycleTracer.java | 187 ++++++++++++++++++ .../java/io/netty/buffer/api/RcSupport.java | 15 +- .../netty/buffer/api/memseg/MemSegBuffer.java | 3 +- 3 files changed, 201 insertions(+), 4 deletions(-) create mode 100644 src/main/java/io/netty/buffer/api/LifecycleTracer.java diff --git a/src/main/java/io/netty/buffer/api/LifecycleTracer.java b/src/main/java/io/netty/buffer/api/LifecycleTracer.java new file mode 100644 index 0000000..123844a --- /dev/null +++ b/src/main/java/io/netty/buffer/api/LifecycleTracer.java @@ -0,0 +1,187 @@ +/* + * Copyright 2021 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: + * + * https://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.buffer.api; + +import java.io.Serial; +import java.util.ArrayDeque; +import java.util.Set; +import java.util.function.Function; +import java.util.stream.Stream; + +abstract class LifecycleTracer { + public static LifecycleTracer get() { + if (Trace.TRACE_LIFECYCLE_DEPTH == 0) { + return new NoOpTracer(); + } + StackTracer stackTracer = new StackTracer(); + stackTracer.addTrace(StackTracer.WALKER.walk(new Trace("allocate", 0))); + return stackTracer; + } + + abstract void acquire(int acquires); + + abstract void drop(int acquires); + + abstract void close(int acquires); + + abstract , T extends RcSupport> Owned send(Owned send, int acquires); + + abstract E attachTrace(E throwable); + + private static final class NoOpTracer extends LifecycleTracer { + @Override + void acquire(int acquires) { + } + + @Override + void drop(int acquires) { + } + + @Override + void close(int acquires) { + } + + @Override + , T extends RcSupport> Owned send(Owned send, int acquires) { + return send; + } + + @Override + E attachTrace(E throwable) { + return throwable; + } + } + + private static final class StackTracer extends LifecycleTracer { + private static final int MAX_TRACE_POINTS = Math.min(Integer.getInteger("MAX_TRACE_POINTS", 50), 1000); + private static final StackWalker WALKER; + static { + int depth = Trace.TRACE_LIFECYCLE_DEPTH; + WALKER = depth > 0 ? StackWalker.getInstance(Set.of(), depth + 2) : null; + } + + private final ArrayDeque traces = new ArrayDeque<>(); + private boolean dropped; + + @Override + void acquire(int acquires) { + Trace trace = WALKER.walk(new Trace("acquire", acquires)); + addTrace(trace); + } + + void addTrace(Trace trace) { + if (traces.size() == MAX_TRACE_POINTS) { + traces.pollFirst(); + } + traces.addLast(trace); + } + + @Override + void drop(int acquires) { + dropped = true; + addTrace(WALKER.walk(new Trace("drop", acquires))); + } + + @Override + void close(int acquires) { + if (!dropped) { + addTrace(WALKER.walk(new Trace("close", acquires))); + } + } + + @Override + , T extends RcSupport> Owned send(Owned send, int acquires) { + Trace sendTrace = new Trace("send", acquires); + sendTrace.sent = true; + addTrace(WALKER.walk(sendTrace)); + return new Owned() { + @Override + public T transferOwnership(Drop drop) { + sendTrace.received = WALKER.walk(new Trace("received", acquires)); + return send.transferOwnership(drop); + } + }; + } + + @Override + E attachTrace(E throwable) { + long timestamp = System.nanoTime(); + for (Trace trace : traces) { + trace.attach(throwable, timestamp); + } + return throwable; + } + } + + private static final class Trace implements Function, Trace> { + private static final int TRACE_LIFECYCLE_DEPTH; + static { + int traceDefault = 0; + //noinspection AssertWithSideEffects + assert (traceDefault = 10) > 0; + TRACE_LIFECYCLE_DEPTH = Math.max(Integer.getInteger("TRACE_LIFECYCLE_DEPTH", traceDefault), 0); + } + + final String name; + final int acquires; + final long timestamp; + boolean sent; + volatile Trace received; + StackWalker.StackFrame[] frames; + + Trace(String name, int acquires) { + this.name = name; + this.acquires = acquires; + timestamp = System.nanoTime(); + } + + @Override + public Trace apply(Stream frames) { + this.frames = frames.limit(TRACE_LIFECYCLE_DEPTH + 1).toArray(StackWalker.StackFrame[]::new); + return this; + } + + public void attach(E throwable, long timestamp) { + Trace recv = received; + String message = sent && recv == null? name + " (sent but not received)" : name; + message += " (current acquires = " + acquires + ") T" + (this.timestamp - timestamp) / 1000 + "µs."; + Traceback exception = new Traceback(message); + StackTraceElement[] stackTrace = new StackTraceElement[frames.length]; + for (int i = 0; i < frames.length; i++) { + stackTrace[i] = frames[i].toStackTraceElement(); + } + exception.setStackTrace(stackTrace); + if (recv != null) { + recv.attach(exception, timestamp); + } + throwable.addSuppressed(exception); + } + } + + private static final class Traceback extends Throwable { + @Serial + private static final long serialVersionUID = 941453986194634605L; + + Traceback(String message) { + super(message); + } + + @Override + public synchronized Throwable fillInStackTrace() { + return this; + } + } +} diff --git a/src/main/java/io/netty/buffer/api/RcSupport.java b/src/main/java/io/netty/buffer/api/RcSupport.java index 2d1003f..2332342 100644 --- a/src/main/java/io/netty/buffer/api/RcSupport.java +++ b/src/main/java/io/netty/buffer/api/RcSupport.java @@ -20,9 +20,11 @@ import java.util.Objects; public abstract class RcSupport, T extends RcSupport> implements Rc { private int acquires; // Closed if negative. private Drop drop; + private final LifecycleTracer tracer; protected RcSupport(Drop drop) { this.drop = drop; + tracer = LifecycleTracer.get(); } /** @@ -35,12 +37,13 @@ public abstract class RcSupport, T extends RcSupport> impl @Override public final I acquire() { if (acquires < 0) { - throw new IllegalStateException("Resource is closed."); + throw attachTrace(new IllegalStateException("Resource is closed.")); } if (acquires == Integer.MAX_VALUE) { throw new IllegalStateException("Cannot acquire more references; counter would overflow."); } acquires++; + tracer.acquire(acquires); return self(); } @@ -54,12 +57,14 @@ public abstract class RcSupport, T extends RcSupport> impl @Override public final void close() { if (acquires == -1) { - throw new IllegalStateException("Double-free: Resource already closed and dropped."); + throw attachTrace(new IllegalStateException("Double-free: Resource already closed and dropped.")); } if (acquires == 0) { + tracer.drop(acquires); drop.drop(impl()); } acquires--; + tracer.close(acquires); } /** @@ -77,11 +82,15 @@ public abstract class RcSupport, T extends RcSupport> impl if (!isOwned()) { throw notSendableException(); } - var owned = prepareSend(); + var owned = tracer.send(prepareSend(), acquires); acquires = -2; // Close without dropping. This also ignore future double-free attempts. return new TransferSend(owned, drop, getClass()); } + protected E attachTrace(E throwable) { + return tracer.attachTrace(throwable); + } + /** * Create an {@link IllegalStateException} with a custom message, tailored to this particular {@link Rc} instance, * for when the object cannot be sent for some reason. diff --git a/src/main/java/io/netty/buffer/api/memseg/MemSegBuffer.java b/src/main/java/io/netty/buffer/api/memseg/MemSegBuffer.java index f68c3fb..dbaf185 100644 --- a/src/main/java/io/netty/buffer/api/memseg/MemSegBuffer.java +++ b/src/main/java/io/netty/buffer/api/memseg/MemSegBuffer.java @@ -451,7 +451,8 @@ class MemSegBuffer extends RcSupport implements Buffer, Re @Override public void ensureWritable(int size, boolean allowCompaction) { if (!isOwned()) { - throw new IllegalStateException("Buffer is not owned. Only owned buffers can call ensureWritable."); + throw attachTrace(new IllegalStateException( + "Buffer is not owned. Only owned buffers can call ensureWritable.")); } if (size < 0) { throw new IllegalArgumentException("Cannot ensure writable for a negative size: " + size + '.');