8221623: Add StackWalker micro benchmarks to jdk repo
authorbchristi
Wed, 25 Sep 2019 14:33:44 -0700
changeset 58347 ac24594d2c8c
parent 58344 d29f0181ba42
child 58348 c29e49148be7
8221623: Add StackWalker micro benchmarks to jdk repo Reviewed-by: dfuchs, mchung, redestad
test/micro/org/openjdk/bench/java/lang/StackWalkBench.java
test/micro/org/openjdk/bench/java/util/logging/LoggingRuntimeMicros.java
test/micro/org/openjdk/bench/vm/lang/ThrowableRuntimeMicros.java
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/micro/org/openjdk/bench/java/lang/StackWalkBench.java	Wed Sep 25 14:33:44 2019 -0700
@@ -0,0 +1,358 @@
+/*
+ * Copyright (c) 2015, 2019 Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+package org.openjdk.bench.java.lang;
+
+import java.lang.StackWalker.StackFrame;
+import java.util.concurrent.TimeUnit;
+import org.openjdk.jmh.annotations.Benchmark;
+import org.openjdk.jmh.annotations.BenchmarkMode;
+import org.openjdk.jmh.annotations.Mode;
+import org.openjdk.jmh.annotations.OutputTimeUnit;
+import org.openjdk.jmh.annotations.Param;
+import org.openjdk.jmh.annotations.Scope;
+import org.openjdk.jmh.annotations.State;
+import org.openjdk.jmh.infra.Blackhole;
+
+/**
+ * Benchmarks for java.lang.StackWalker
+ */
+@State(value=Scope.Benchmark)
+@BenchmarkMode(Mode.AverageTime)
+@OutputTimeUnit(TimeUnit.NANOSECONDS)
+public class StackWalkBench {
+    private static final StackWalker WALKER_DEFAULT = StackWalker.getInstance();
+
+    private static final StackWalker WALKER_CLASS =
+        StackWalker.getInstance(StackWalker.Option.RETAIN_CLASS_REFERENCE);
+
+    // TestStack will add this number of calls to the call stack
+    @Param({"4", "100", "1000"})
+    // For more thorough testing, consider:
+    // @Param({"4", "10", "100", "256", "1000"})
+    public int depth;
+
+    // Only used by swFilterCallerClass, to specify (roughly) how far back the
+    // call stack the target class will be found.  Not needed by other
+    // benchmarks, so not a @Param by default.
+    // @Param({"4"})
+    public int mark = 4;
+
+    /** Build a call stack of a given size, then run trigger code in it.
+      * (Does not account for existing frames higher up in the JMH machinery).
+      */
+    public static class TestStack {
+        final long fence;
+        long current;
+        final Runnable trigger;
+
+        public TestStack(long max, Runnable trigger) {
+          this.fence = max;
+          this.current = 0;
+          this.trigger = trigger;
+        }
+
+        public void start() {
+            one();
+        }
+
+        public void one() {
+            if (check()) {
+                two();
+            }
+        }
+
+        void two() {
+           if (check()) {
+              three();
+           }
+        }
+
+        private void three() {
+            if (check()) {
+               one();
+            }
+        }
+
+        boolean check() {
+            if (++current == fence) {
+                trigger.run();
+                return false;
+            } else {
+                return true;
+            }
+        }
+    }
+
+    /* Class to look for when testing filtering */
+    static class TestMarker {
+        public void call(MarkedTestStack test) {
+            test.marked();
+        }
+    }
+
+    /** Call stack to test filtering.
+     *  TestMarker will make a call on the stack.
+     */
+    static class MarkedTestStack extends TestStack {
+        long mark;
+
+        /**
+         * @param mark How far back the stack should the TestMarker be found?
+         */
+        public MarkedTestStack(long max, long mark, Runnable trigger) {
+            super(max, trigger);
+            if (mark > max) {
+                throw new IllegalArgumentException("mark must be <= max");
+            }
+            this.mark = max - mark; // Count backwards from the completed call stack
+        }
+        @Override
+        public void start() {
+            if (mark == 0) {
+                mark();
+            } else {
+                super.one();
+            }
+        }
+        @Override
+        boolean check() {
+           if (++current == mark) {
+               mark();
+               return false;
+           } else if (current == fence) {
+              trigger.run();
+              return false;
+           } else {
+               return true;
+           }
+        }
+        void mark() {
+            new TestMarker().call(this);
+        }
+        public void marked() {
+            if (current < fence) {
+                if (check()) {
+                    one();
+                }
+            } else {
+                trigger.run();
+            }
+        }
+    }
+
+    /**
+     * StackWalker.forEach() with default options
+     */
+    @Benchmark
+    public void forEach_DefaultOpts(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                WALKER_DEFAULT.forEach(localBH::consume);
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    /**
+     * Use Stackwalker.walk() to fetch class names
+     */
+    @Benchmark
+    public void walk_ClassNames(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                WALKER_DEFAULT.walk(s -> {
+                    s.map(StackFrame::getClassName).forEach(localBH::consume);
+                    return null;
+                });
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    /**
+     * Use Stackwalker.walk() to fetch method names
+     */
+    @Benchmark
+    public void walk_MethodNames(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                WALKER_DEFAULT.walk( s -> {
+                    s.map(StackFrame::getMethodName).forEach(localBH::consume);
+                    return null;
+                });
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    /**
+     * Use Stackwalker.walk() to fetch declaring class instances
+     */
+    @Benchmark
+    public void walk_DeclaringClass(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                WALKER_CLASS.walk(s -> {
+                    s.map(StackFrame::getDeclaringClass).forEach(localBH::consume);
+                    return null;
+                });
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    /**
+     * Use StackWalker.walk() to fetch StackTraceElements
+     */
+    @Benchmark
+    public void walk_StackTraceElements(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                WALKER_DEFAULT.walk(s -> {
+                    s.map(StackFrame::toStackTraceElement).forEach(localBH::consume);
+                    return null;
+                });
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    /**
+     * StackWalker.getCallerClass()
+     */
+    @Benchmark
+    public void getCallerClass(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                localBH.consume(WALKER_CLASS.getCallerClass());
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    /**
+     * Use StackWalker.walk() to filter the StackFrames, looking for the
+     * TestMarker class, which will be (approximately) 'mark' calls back up the
+     * call stack.
+     */
+    @Benchmark
+    public void walk_filterCallerClass(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+
+        new MarkedTestStack(depth, mark, new Runnable() {
+            public void run() {
+                // To be comparable with Reflection.getCallerClass(), return the Class object
+                WALKER_CLASS.walk(s -> {
+                    localBH.consume(s.filter(f -> TestMarker.class.equals(f.getDeclaringClass())).findFirst().get().getDeclaringClass());
+                    return null;
+                });
+                done[0] = true;
+            }
+        }).start();
+
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    /**
+     * Use StackWalker.walk() to filter the StackFrames, looking for the
+     * TestMarker class, which will be (approximately) depth/2 calls back up the
+     * call stack.
+     */
+    @Benchmark
+    public void walk_filterCallerClassHalfStack(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+
+        new MarkedTestStack(depth, depth / 2, new Runnable() {
+            public void run() {
+                // To be comparable with Reflection.getCallerClass(), return the Class object
+                WALKER_CLASS.walk(s -> {
+                    localBH.consume(s.filter((f) -> TestMarker.class.equals(f.getDeclaringClass())).findFirst().get().getDeclaringClass());
+                    return null;
+                });
+                done[0] = true;
+            }
+        }).start();
+
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    // TODO: add swConsumeFramesWithReflection
+    // TODO: add swFilterOutStreamClasses
+
+//    // This benchmark is for collecting performance counter data
+//    static PerfCounter streamTime = PerfCounter.newPerfCounter("jdk.stackwalk.testStreamsElapsedTime");
+//    static PerfCounter  numStream = PerfCounter.newPerfCounter("jdk.stackwalk.numTestStreams");
+//    // @Benchmark
+//    public void swStkFrmsTimed(Blackhole bh) {
+//        final Blackhole localBH = bh;
+//        final boolean[] done = {false};
+//        new TestStack(depth, new Runnable() {
+//            public void run() {
+//                long t0 = System.nanoTime();
+//                WALKER_DEFAULT.forEach(localBH::consume);
+//                streamTime.addElapsedTimeFrom(t0);
+//                numStream.increment();
+//                done[0] = true;
+//            }
+//        }).start();
+//        if (!done[0]) {
+//            throw new RuntimeException();
+//        }
+//    }
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/micro/org/openjdk/bench/java/util/logging/LoggingRuntimeMicros.java	Wed Sep 25 14:33:44 2019 -0700
@@ -0,0 +1,175 @@
+/*
+ * Copyright (c) 2015, 2019 Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+package org.openjdk.bench.java.util.logging;
+
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicInteger;
+import java.util.logging.LogRecord;
+import org.openjdk.jmh.annotations.Benchmark;
+import org.openjdk.jmh.annotations.BenchmarkMode;
+import org.openjdk.jmh.annotations.Mode;
+import org.openjdk.jmh.annotations.OutputTimeUnit;
+import org.openjdk.jmh.annotations.Param;
+import org.openjdk.jmh.annotations.Scope;
+import org.openjdk.jmh.annotations.State;
+import org.openjdk.jmh.infra.Blackhole;
+
+@State(value = Scope.Benchmark)
+@BenchmarkMode(Mode.AverageTime)
+@OutputTimeUnit(TimeUnit.NANOSECONDS)
+public class LoggingRuntimeMicros {
+
+    // TestStack will add this number of calls to the call stack
+    @Param({"4", "100", "1000"})
+    // For more thorough testing, consider:
+    // @Param({"4", "10", "100", "256", "1000"})
+    public int depth;
+
+    /** Logging handler for testing logging calls. */
+    @State(value = Scope.Thread) // create a separate one for each worker thread
+    public static class TestHandler extends java.util.logging.Handler {
+        private final static AtomicInteger serialNum = new AtomicInteger(0);
+
+        private final java.util.logging.Logger logger;
+        private volatile LogRecord record;
+
+        public TestHandler() {
+            // Each instance uses its own logger
+            logger = java.util.logging.Logger.getLogger("StackWalkBench" + serialNum.incrementAndGet());
+            logger.setUseParentHandlers(false);
+            logger.addHandler(this);
+        }
+
+        @Override
+        public void publish(LogRecord record) {
+            record.getSourceMethodName();
+            this.record = record;
+        }
+
+        private LogRecord reset() {
+            LogRecord record = this.record;
+            this.record = null;
+            return record;
+        }
+
+        public final LogRecord testInferCaller(String msg) {
+            logger.info(msg);
+            LogRecord rec = this.reset();
+            if (!"testInferCaller".equals(rec.getSourceMethodName())) {
+                throw new RuntimeException("bad caller: "
+                        + rec.getSourceClassName() + "."
+                        + rec.getSourceMethodName());
+            }
+            return rec;
+        }
+
+        public final LogRecord testLogp(String msg) {
+            logger.logp(java.util.logging.Level.INFO, "foo", "bar", msg);
+            LogRecord rec = this.reset();
+            if (!"bar".equals(rec.getSourceMethodName())) {
+                throw new RuntimeException("bad caller: "
+                        + rec.getSourceClassName() + "."
+                        + rec.getSourceMethodName());
+            }
+            return rec;
+        }
+        @Override public void flush() {}
+        @Override public void close() throws SecurityException {}
+    }
+
+    /** Build a call stack of a given size, then run trigger code in it.
+      * (Does not account for existing frames higher up in the JMH machinery).
+      */
+    static class TestStack {
+        final long fence;
+        long current;
+        final Runnable trigger;
+
+        TestStack(long max, Runnable trigger) {
+            this.fence = max;
+            this.current = 0;
+            this.trigger = trigger;
+        }
+
+        public void start() {
+            one();
+        }
+
+        public void one() {
+            if (check()) {
+                two();
+            }
+        }
+
+        void two() {
+            if (check()) {
+                three();
+            }
+        }
+
+        private void three() {
+            if (check()) {
+                one();
+            }
+        }
+
+        boolean check() {
+            if (++current == fence) {
+                trigger.run();
+                return false;
+            } else {
+                return true;
+            }
+        }
+    }
+
+    @Benchmark
+    public void testLoggingInferCaller(TestHandler handler, Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                localBH.consume(handler.testInferCaller("test"));
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    @Benchmark
+    public void testLoggingLogp(TestHandler handler, Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                localBH.consume(handler.testLogp("test"));
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/micro/org/openjdk/bench/vm/lang/ThrowableRuntimeMicros.java	Wed Sep 25 14:33:44 2019 -0700
@@ -0,0 +1,139 @@
+/*
+ * Copyright (c) 2015, 2019 Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+package org.openjdk.bench.vm.lang;
+
+import java.util.concurrent.TimeUnit;
+import org.openjdk.jmh.annotations.Benchmark;
+import org.openjdk.jmh.annotations.BenchmarkMode;
+import org.openjdk.jmh.annotations.Mode;
+import org.openjdk.jmh.annotations.OutputTimeUnit;
+import org.openjdk.jmh.annotations.Param;
+import org.openjdk.jmh.annotations.Scope;
+import org.openjdk.jmh.annotations.State;
+import org.openjdk.jmh.infra.Blackhole;
+
+@State(value = Scope.Benchmark)
+@BenchmarkMode(Mode.AverageTime)
+@OutputTimeUnit(TimeUnit.NANOSECONDS)
+public class ThrowableRuntimeMicros {
+
+    // TestStack will add this number of calls to the call stack
+    @Param({"4", "100", "1000"})
+    // For more thorough testing, consider:
+    // @Param({"4", "10", "100", "256", "1000"})
+    public int depth;
+
+    /** Build a call stack of a given size, then run trigger code in it.
+      * (Does not account for existing frames higher up in the JMH machinery).
+      */
+    static class TestStack {
+        final long fence;
+        long current;
+        final Runnable trigger;
+
+        TestStack(long max, Runnable trigger) {
+            this.fence = max;
+            this.current = 0;
+            this.trigger = trigger;
+        }
+
+        public void start() {
+            one();
+        }
+
+        public void one() {
+            if (check()) {
+                two();
+            }
+        }
+
+        void two() {
+            if (check()) {
+                three();
+            }
+        }
+
+        private void three() {
+            if (check()) {
+                one();
+            }
+        }
+
+        boolean check() {
+            if (++current == fence) {
+                trigger.run();
+                return false;
+            } else {
+                return true;
+            }
+        }
+    }
+
+    @Benchmark
+    public void testThrowableInit(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                localBH.consume(new Throwable());
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    @Benchmark
+    public void testThrowableGetStackTrace(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                localBH.consume(new Throwable().getStackTrace());
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+
+    @Benchmark
+    public void testThrowableSTEtoString(Blackhole bh) {
+        final Blackhole localBH = bh;
+        final boolean[] done = {false};
+        new TestStack(depth, new Runnable() {
+            public void run() {
+                Throwable t = new Throwable();
+                for (StackTraceElement ste : t.getStackTrace()) {
+                    localBH.consume(ste.toString());
+                }
+                done[0] = true;
+            }
+        }).start();
+        if (!done[0]) {
+            throw new RuntimeException();
+        }
+    }
+}