java.lang.reflect.Proxy: Huge exception stack trace

Question

Here is a simple Java application:

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;

public class Main {

    interface MyInterface {
        void myMethod();
    }

    public static void main(String[] args) {
        MyInterface myInterface = (MyInterface) Proxy.newProxyInstance(Main.class.getClassLoader(), new Class[] {MyInterface.class},
            new InvocationHandler() {
                @Override
                public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
                    return method.invoke(proxy, args);
                }
            });
        myInterface.myMethod();
    }
}

I would expect to get a simple StackOverflowError here, because I am recursively calling the same method on the proxy instance.

However, the stack trace produced by the exception contains millions of lines and hundreds of MBs in size.

The first part of the stack trace starts like this:

java.lang.reflect.UndeclaredThrowableException
    at $Proxy0.myMethod(Unknown Source)
    at Main.main(Main.java:22)
Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at Main$1.invoke(Main.java:18)
    ... 2 more
Caused by: java.lang.reflect.UndeclaredThrowableException
    at $Proxy0.myMethod(Unknown Source)
    ... 7 more
Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at Main$1.invoke(Main.java:18)
    ... 8 more

and extends to:

Caused by: java.lang.reflect.UndeclaredThrowableException
    at $Proxy0.myMethod(Unknown Source)
    ... 1022 more

Then follow millions of lines like:

Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at Main$1.invoke(Main.java:18)
    at $Proxy0.myMethod(Unknown Source)
    at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at Main$1.invoke(Main.java:18)
    .......

and:

Caused by: java.lang.reflect.UndeclaredThrowableException
    at $Proxy0.myMethod(Unknown Source)
    at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at Main$1.invoke(Main.java:18)
    at $Proxy0.myMethod(Unknown Source)
    at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at Main$1.invoke(Main.java:18)
    .......

The last printed line is (after the repeating sequence above):

Exception: java.lang.StackOverflowError thrown from the UncaughtExceptionHandler in thread "main"

I suspected that stack trace generation mechanism was calling some methods on the proxy instance (maybe toString to print it, or something else), thus repeating the recursion over and over again (because each method call on the proxy leads to infinite recursion), but the total count of proxy method executions is 1919 (measured by incrementing a counter in the InvocationHandler.invoke method).

In my real use case I fixed the infinite recursion issue of course; I am just curious if anyone knows if this is some bug or there is a reasonable explanation?

Java version:

java version "1.8.0_65"
Java(TM) SE Runtime Environment (build 1.8.0_65-b17)
Java HotSpot(TM) 64-Bit Server VM (build 25.65-b01, mixed mode)

EDIT

@JiriTousek and @AndrewWilliamson kindly provided an analysis of what may be the cause for this. I implemented a simulation based on their input:

import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.UndeclaredThrowableException;

public class Test {
    private static int counter = 0;

    public static void main(String[] args) {
        proxy();
    }

    private static void proxy() {
        try {
            methodInvoke();
        } catch (Throwable e) {
            throw new UndeclaredThrowableException(e);
        }
    }

    private static void methodInvoke() throws InvocationTargetException {
        try {
            myMethod();
        } catch (Throwable e) {
            throw new InvocationTargetException(e);
        }
    }

    private static void myMethod() {
        if (counter++ == 5) {
            throw new StackOverflowError();
        }
        proxy();
    }
}

This results in the following stack trace:

Exception in thread "main" java.lang.reflect.UndeclaredThrowableException
    at Test.proxy(Test.java:16)
    at Test.main(Test.java:9)
Caused by: java.lang.reflect.InvocationTargetException
    at Test.methodInvoke(Test.java:24)
    at Test.proxy(Test.java:14)
    ... 1 more
Caused by: java.lang.reflect.UndeclaredThrowableException
    at Test.proxy(Test.java:16)
    at Test.myMethod(Test.java:32)
    at Test.methodInvoke(Test.java:22)
    ... 2 more
Caused by: java.lang.reflect.InvocationTargetException
    at Test.methodInvoke(Test.java:24)
    at Test.proxy(Test.java:14)
    ... 4 more
Caused by: java.lang.reflect.UndeclaredThrowableException
    at Test.proxy(Test.java:16)
    at Test.myMethod(Test.java:32)
    at Test.methodInvoke(Test.java:22)
    ... 5 more
Caused by: java.lang.reflect.InvocationTargetException
    at Test.methodInvoke(Test.java:24)
    at Test.proxy(Test.java:14)
    ... 7 more
Caused by: java.lang.reflect.UndeclaredThrowableException
    at Test.proxy(Test.java:16)
    at Test.myMethod(Test.java:32)
    at Test.methodInvoke(Test.java:22)
    ... 8 more
Caused by: java.lang.reflect.InvocationTargetException
    at Test.methodInvoke(Test.java:24)
    at Test.proxy(Test.java:14)
    ... 10 more
Caused by: java.lang.reflect.UndeclaredThrowableException
    at Test.proxy(Test.java:16)
    at Test.myMethod(Test.java:32)
    at Test.methodInvoke(Test.java:22)
    ... 11 more
Caused by: java.lang.reflect.InvocationTargetException
    at Test.methodInvoke(Test.java:24)
    at Test.proxy(Test.java:14)
    ... 13 more
Caused by: java.lang.reflect.UndeclaredThrowableException
    at Test.proxy(Test.java:16)
    at Test.myMethod(Test.java:32)
    at Test.methodInvoke(Test.java:22)
    ... 14 more
Caused by: java.lang.reflect.InvocationTargetException
    at Test.methodInvoke(Test.java:24)
    at Test.proxy(Test.java:14)
    ... 16 more
Caused by: java.lang.StackOverflowError
    at Test.myMethod(Test.java:30)
    at Test.methodInvoke(Test.java:22)
    ... 17 more

So, there is no line numbers growth for each stack frame.

I thought so - it _is_ a stack overflow initially, but the `invoke` call is wrapping it in a different exception type. — Andrew Williamson, Feb 19 '16 at 18:20
@AndrewWilliamson Why millions of lines then? Shouldn't the final `Caused by` only print a 1000 or so lines, while wrapper exceptions printing only their part of the trace? — Dragan Bozanovic, Feb 19 '16 at 18:24
MyInterface.myMethod does not declare that it throws any checked exceptions, yet your implementation _does_ throw, from `method.invoke`. So at each level of recursion, an exception is thrown, and you get the whole chain of `UndeclaredThrowableException` etc. What would have been one line in the stack trace is now 10 instead. — Andrew Williamson, Feb 19 '16 at 18:36
Please see my answer for a rough estimate of number of lines printed and why there's so many. Basically, since the stack trace grows with each level of invocation, the number of lines grows quadratically with number of invocation (i.e. number of invocations to the power of two). — Jiri Tousek, Feb 19 '16 at 19:01

Jiri Tousek · Answer 1 · 2016-02-19T18:58:56.847

3

My interpretation of this stack trace is:

When the stack overflow finally happened, a StackOverflowError was thrown
This error was caught by method.invoke() and translated into an InvocationTargetException (as per it's javadoc), with the original exception as a cause
Since this exception is a checked exception, the Proxy could not let it fall through itself, so it caught it and translated it into a UndeclaredThrowableException, again with the previous as a cause

This way, for each level of recursion before stack overflow you got two other "caused by" exceptions along with their stack traces - a lot of output. As for how much output, let's guesstimate it:

about 2000 invocations as per your post
in each invocation, the stack trace seems to grow by 5 lines
2 errors and stack traces printed for each invocation

So the biggest stack trace will have some 10000 lines, average stack trace will have about 5000 lines, everything is printed twice (once for each exception type), that sums up to about 2000 * 5000 * 2 = 20 millions of lines.

edited Feb 19 '16 at 18:58

answered Feb 19 '16 at 18:18

Jiri Tousek

12,211
5
29
43

I edited my question with a simulation based on your analysis. I would say that numbers don't match, but I may still be missing something. – Dragan Bozanovic Feb 19 '16 at 19:33
It looks like in your simulation, Java is cutting off the stack traces far more aggressively. If you have the original stack trace, you can look at the bottom and top to see whether the stack trace for a single exception is growing or not. Your simulation also shows that the cause for the long chain of these two exceptions is indeed what I described. – Jiri Tousek Feb 19 '16 at 19:36
+1 for mathematical analysis. Actually, the cause for enormous printed trace was that the trace was not truncated with `... more` notation when the depth of identical traces is longer than 1024. More details in my answer. – Dragan Bozanovic Feb 20 '16 at 21:02

score 1 · Accepted Answer · edited May 23 '17 at 12:15

The printed stack trace is not truncated when depth of identical traces is longer than 1024 (default value). That's why the last truncated trace ends with ... 1022 more while all of the subsequent ones are printed fully.

The default can be changed by setting MaxJavaStackTraceDepth JVM argument to the desired value. When I increased it for the original example with Proxy by running it with -XX:MaxJavaStackTraceDepth=8192, the entire printed stack trace dropped to about 12500 lines, ending with:

Caused by: java.lang.reflect.InvocationTargetException
    at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at Main1$1.invoke(Main1.java:16)
    ... 7003 more
Caused by: java.lang.reflect.UndeclaredThrowableException
    at $Proxy0.myMethod(Unknown Source)
    ... 7007 more

Exception: java.lang.StackOverflowError thrown from the UncaughtExceptionHandler in thread "main"

java.lang.reflect.Proxy: Huge exception stack trace

2 Answers2