2016-02-19 3 views
3

Вот простое приложение Java:java.lang.reflect.Proxy: Огромный стек исключений трассировки

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(); 
    } 
} 

Я бы ожидать, чтобы получить простой StackOverflowError здесь, потому что я рекурсивного вызова того же метода на прокси пример.

Однако трассировка стека, созданная по исключению, содержит миллионы строк и сотни МБ в размере.

Первая часть трассировки стека начинается так:

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 

и распространяется на:

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

Затем следуют миллионы строк, как:

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) 
    ....... 

и:

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) 
    ....... 

Последняя печататься строка (после повторяющейся последовательности выше):

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

Я подозревал, что механизм генерации трассировки стека звала некоторые методы прокси экземпляра (возможно toString напечатать его, или что-то еще), повторяя повторение рекурсии снова и снова (потому что каждый вызов метода на прокси приводит к бесконечной рекурсии), но общий счет выполнения прокси-метода равен 1919 (измеряется путем увеличения счетчика в методе InvocationHandler.invoke).

В моем реальном случае использования я, конечно, исправил проблему бесконечной рекурсии; Мне просто интересно, если кто-нибудь знает, если это какая-то ошибка или есть разумное объяснение?

версия Java:

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 и @AndrewWilliamson любезно предоставлен анализ того, что может быть причиной для этого. Я реализовал моделирование, основанное на их входе:

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(); 
    } 
} 

Это приводит к следующей трассировке стеки:

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 

Таким образом, нет никакого роста числа линий для каждого кадра стека.

+0

Какой тип исключения является окончательным «Вызванный»? –

+0

@AndrewWilliamson Edited. –

+0

Я так и думал - это переполнение стека изначально, но вызов 'invoke' переносит его в другой тип исключения. –

ответ

0

Отпечатанная трассировка стека не равна truncated, когда глубина идентичных трасс длиннее 1024 (значение по умолчанию). Вот почему последняя усеченная трасса заканчивается ... 1022 more, а все последующие печатаются полностью.

Значение по умолчанию можно изменить, установив аргумент JVM MaxJavaStackTraceDepth в нужное значение. Когда я увеличил его на исходном примере с Proxy, запустив его с -XX:MaxJavaStackTraceDepth=8192, весь напечатанный трассировки стека упал до 12500 линий, заканчивая:

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" 
3

Моя интерпретация этого стека следа:

  • Когда переполнение стека, наконец, произошло, StackOverflowError был выброшен
  • Эта ошибка была поймана method.invoke() и переводится в InvocationTargetException (согласно it's javadoc), с Исходное исключение в качестве причины
  • Поскольку это исключение является проверенным исключением, прокси не мог позволить ему провалиться через него, поэтому он поймал его и перевел в UndeclaredThrowableException, снова с предыдущим в качестве причины

Таким образом, для каждого уровня рекурсии до переполнения стека вы получили два других исключения из-за «из-за» вместе со своими трассировками стека - много выходных данных. Что же касается того, сколько продукции, давайте чутьем его:

  • около 2000 вызовы как на ваш пост
  • в каждом вызове, трассировки стека, кажется, растет на 5 линий
  • 2 ошибок и трассировки стека распечатанные для каждого вызов

Так самый большой трассировки стека будет иметь некоторые 10000 строк, средний след стека будет иметь около 5000 строк, все печатается дважды (один раз для каждого типа исключения), которое подводит итог около 2000 * 5000 * 2 = 20 миллионов линии.

+0

Я редактировал свой вопрос с помощью симуляции, основанной на вашем анализе. Я бы сказал, что цифры не совпадают, но я все еще могу что-то упустить. –

+0

Похоже, что в вашей симуляции Java значительно более агрессивно отключает следы стека. Если у вас есть исходная трассировка стека, вы можете посмотреть внизу и сверху, чтобы увидеть, растет или нет трассировка стека для одного исключения. Ваша симуляция также показывает, что причиной длинной цепочки этих двух исключений является то, что я описал. –

+0

+1 для математического анализа. Фактически причиной огромной печатной трассы было то, что след не был усечен символом «... больше», когда глубина идентичных следов длиннее 1024. Более подробно в моем ответе. –