Merge pull request #34 from netty/tracer

Add LifecycleTracer to help debug lifecycle/ownership issues

Author: chrisvest

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 <I extends Rc<I>, T extends RcSupport<I, T>> Owned<T> send(Owned<T> send, int acquires);
+
+    abstract <E extends Throwable> 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
+        <I extends Rc<I>, T extends RcSupport<I, T>> Owned<T> send(Owned<T> send, int acquires) {
+            return send;
+        }
+
+        @Override
+        <E extends Throwable> 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<Trace> 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
+        <I extends Rc<I>, T extends RcSupport<I, T>> Owned<T> send(Owned<T> send, int acquires) {
+            Trace sendTrace = new Trace("send", acquires);
+            sendTrace.sent = true;
+            addTrace(WALKER.walk(sendTrace));
+            return new Owned<T>() {
+                @Override
+                public T transferOwnership(Drop<T> drop) {
+                    sendTrace.received = WALKER.walk(new Trace("received", acquires));
+                    return send.transferOwnership(drop);
+                }
+            };
+        }
+
+        @Override
+        <E extends Throwable> 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<Stream<StackWalker.StackFrame>, 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<StackWalker.StackFrame> frames) {
+            this.frames = frames.limit(TRACE_LIFECYCLE_DEPTH + 1).toArray(StackWalker.StackFrame[]::new);
+            return this;
+        }
+
+        public <E extends Throwable> 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;
+        }
+    }
+}

src/main/java/io/netty/buffer/api/RcSupport.java

@@ -20,9 +20,11 @@
 public abstract class RcSupport<I extends Rc<I>, T extends RcSupport<I, T>> implements Rc<I> {
     private int acquires; // Closed if negative.
     private Drop<T> drop;
+    private final LifecycleTracer tracer;
 
     protected RcSupport(Drop<T> drop) {
         this.drop = drop;
+        tracer = LifecycleTracer.get();
     }
 
     /**
@@ -35,12 +37,13 @@ protected RcSupport(Drop<T> drop) {
     @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 final I acquire() {
     @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 final Send<I> send() {
         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<I, T>(owned, drop, getClass());
     }
 
+    protected <E extends Throwable> 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.

src/main/java/io/netty/buffer/api/memseg/MemSegBuffer.java

@@ -451,7 +451,8 @@ public int bytesLeft() {
     @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 + '.');