Развертывание кода Java в рабочей среде ограничивает возможности устранения неполадок. О подключении к вашему рабочему приложению с помощью отладчика обычно не может быть и речи, и вы, возможно, даже не сможете получить доступ к консоли. Таким образом, даже при мониторинге вы в конечном итоге будете устранять многие проблемы посмертно. Это означает просмотр журналов и, если вам повезет, работа с трассировкой стека Java.
Правильно, я сказал, что вам повезло, если у вас есть трассировка стека. Это все равно что получить в руки компас, карту и билет на самолет первого класса одновременно! Давайте поговорим о том, что такое трассировка стека Java и как вы можете ее использовать.
Что такое трассировка стека Java?
Трассировка стека, также называемая обратной трассировкой стека или даже просто обратной трассировкой, представляет собой список кадров стека. Эти кадры представляют собой момент во время выполнения приложения. Фрейм стека – это информация о методе или функции, которые вызвал ваш код. Таким образом, трассировка стека Java – это список фреймов, который начинается с текущего метода и продолжается до момента запуска программы.
Иногда возникает путаница между стеком и стеком. Стек – это структура данных, которая действует как стопка бумаг на вашем столе: она приходит первой и уходит последней. Вы добавляете документы в стопку и удаляете их в порядке, обратном тому, в каком вы их туда положили. Стек, более точно называемый средой выполнения или стеком вызовов, представляет собой набор фреймов стека, которые программа создает во время выполнения, организованный в структуру данных стека.
Давайте рассмотрим пример.
Пример трассировки стека Java
Давайте взглянем на Java-программу. Этот класс вызывает четыре метода и выводит трассировку стека на консоль из последнего.
public class StackTrace {
public static void main(String[] args) {
a();
}
static void a() {
b();
}
static void b() {
c();
}
static void c() {
d();
}
static void d() {
Thread.dumpStack();
}
}Когда вы запустите класс, вы увидите что-то вроде этого:
java.lang.Exception: Stack trace at java.base/java.lang.Thread.dumpStack(Thread.java:1383) at com.ericgoebelbecker.stacktraces.StackTrace.d(StackTrace.java:23) at com.ericgoebelbecker.stacktraces.StackTrace.c(StackTrace.java:19) at com.ericgoebelbecker.stacktraces.StackTrace.b(StackTrace.java:15) at com.ericgoebelbecker.stacktraces.StackTrace.a(StackTrace.java:11) at com.ericgoebelbecker.stacktraces.StackTrace.main(StackTrace.java:7)
Метод d()() находится в верхней части стека, потому что именно там приложение сгенерировало трассировку. Метод main() находится внизу, потому что именно там запустилась программа. Когда программа запустилась, среда выполнения Java выполнила метод main(). Main() вызывается a(). A() называется b(), а b() называется c(), который называется d(). Наконец, d() вызвал dumpStack(), который сгенерировал выходные данные. Эта трассировка стека Java дает нам представление о том, что сделала программа, в том порядке, в котором она это сделала.
Трассировка стека Java – это моментальный снимок определенного момента времени. Вы можете увидеть, где находилось ваше приложение и как оно туда попало. Это ценная информация, которую вы можете использовать несколькими различными способами.
Как использовать трассировки стека Java
Теперь, когда вы увидели, что показывают трассировки стека Java, как вы можете их использовать?
Исключения Java
Трассировки стека и исключения часто связаны друг с другом. Когда вы видите, что приложение Java выдает исключение, вы обычно видите, что трассировка стека регистрируется вместе с ним. Это происходит из-за того, как работают исключения.
Когда код Java выдает исключение, среда выполнения ищет в стеке метод, у которого есть обработчик, который может его обработать. Если он находит один из них, он передает ему исключение. Если этого не произойдет, программа завершит работу. Таким образом, исключения и стек вызовов связаны напрямую. Понимание этой взаимосвязи поможет вам выяснить, почему ваш код выдал исключение.
Давайте изменим наш пример кода.
Во-первых, измените метод d():
static void d() {
throw new NullPointerException("Oops!");
}
Затем измените main() и a(), чтобы main мог перехватить исключение. Вам нужно будет добавить проверенное исключение в a(), чтобы код был скомпилирован.
public static void main(String[] args)
{
try {
a();
} catch (InvalidClassException ice) {
System.err.println(ice.getMessage());
}
}
static void a() throws InvalidClassException
{
b();
}Вы намеренно ловите “неправильное” исключение. Запустите этот код и посмотрите, что произойдет.
Exception in thread "main" java.lang.NullPointerException: Oops! at com.ericgoebelbecker.stacktraces.StackTrace.d(StackTrace.java:29) at com.ericgoebelbecker.stacktraces.StackTrace.c(StackTrace.java:24) at com.ericgoebelbecker.stacktraces.StackTrace.b(StackTrace.java:20) at com.ericgoebelbecker.stacktraces.StackTrace.a(StackTrace.java:16) at com.ericgoebelbecker.stacktraces.StackTrace.main(StackTrace.java:9)
Исключение появилось в стеке после main(), потому что вы пытались перехватить другое исключение. Таким образом, среда выполнения выбросила его, завершив работу приложения. Однако вы все еще можете видеть трассировку стека, так что легко определить, что произошло.
Теперь измените main(), чтобы вместо этого перехватить исключение NullPointerException. Вы также можете удалить проверенное исключение из a().
public static void main(String[] args) {
try {
a();
} catch (NullPointerException ice) {
System.err.println(ice.getMessage());
}
}
static void a() {
b();
}
Повторно запустите программу.
Oops!
Мы потеряли трассировку стека! Распечатав только сообщение, прикрепленное к исключению, вы упустили какой-то важный контекст. Если только вы не можете вспомнить, почему вы написали Упс! в этом сообщении отслеживание этой проблемы будет сложным. Давайте попробуем еще раз.
public static void main(String[] args) {
try {
a();
} catch (NullPointerException npe) {
npe.printStackTrace();
}
}Повторно запустите приложение.
java.lang.NullPointerException: Oops! at com.ericgoebelbecker.stacktraces.StackTrace.d(StackTrace.java:28) at com.ericgoebelbecker.stacktraces.StackTrace.c(StackTrace.java:24) at com.ericgoebelbecker.stacktraces.StackTrace.b(StackTrace.java:20) at com.ericgoebelbecker.stacktraces.StackTrace.a(StackTrace.java:16) at com.ericgoebelbecker.stacktraces.StackTrace.main(StackTrace.java:9)
Так-то лучше! Мы видим трассировку стека, и она заканчивается на d(), где произошло исключение, даже несмотря на то, что main() напечатала его.
Протоколирование трассировок стека Java
Что делать, если вы хотите вывести сообщение об ошибке не на консоль, а в файл журнала? Хорошей новостью является то, что большинство регистраторов, включая Log4j и Logback, будут записывать исключения с трассировками стека, если вы вызываете их с правильными аргументами.
Передайте объект исключения в качестве последнего аргумента сообщения без директивы форматирования. Итак, если вы использовали Log4j или Logback с примером кода, подобным этому:
logger.error("Something bad happened:", npe);
Вы увидите это в своем файле журнала:
Something bad happened: java.lang.NullPointerException: Oops! at com.ericgoebelbecker.stacktraces.StackTrace.d(StackTrace.java:28) at com.ericgoebelbecker.stacktraces.StackTrace.c(StackTrace.java:24) at com.ericgoebelbecker.stacktraces.StackTrace.b(StackTrace.java:20) at com.ericgoebelbecker.stacktraces.StackTrace.a(StackTrace.java:16) at com.ericgoebelbecker.stacktraces.StackTrace.main(StackTrace.java:9)
Одна из лучших вещей, которые вы можете сделать с исключениями и трассировками стека, – это протоколировать их, чтобы вы могли использовать их для изоляции проблемы. Если у вас войдет в привычку печатать полезные сообщения журнала с такими подробностями, как трассировка стека и индексация журнала, инструменты поиска, такие как Scalyr, станут одним из самых мощных инструментов в вашем наборе инструментов для устранения неполадок.
Отладчик Java
Отладчики работают, беря под контроль время выполнения программы и позволяя вам одновременно наблюдать за ней и управлять ею. Для этого он показывает вам программный стек и позволяет перемещаться по нему в любом направлении. Когда вы находитесь в отладчике, вы получаете более полную картину фрейма стека, чем при просмотре трассировок стека в сообщении журнала.
Давайте внесем небольшое изменение в код, а затем бросим образец кода в отладчик.
Сначала добавьте локальную переменную в метод d():
static void d() {
String message = "Oops."
throw new NullPointerException(message);
}
Затем добавьте точку останова, где d() выдает исключение в вашем отладчике. Я использую Intellij debugger для этого изображения.
Здесь вы можете видеть, что строка, которую мы добавили в d(), является частью фрейма стека, потому что это локальная переменная. Отладчики работают внутри стека и дают вам подробную картину каждого кадра.
Принудительное выполнение дампа потока
Дампы потоков – отличные инструменты для посмертного анализа, но они также могут быть полезны при проблемах во время выполнения. Если ваше приложение перестает отвечать на запросы или потребляет больше процессора или памяти, чем вы ожидаете, вы можете получить информацию о запущенном приложении с помощью jstack.
Измените main(), чтобы приложение работало до тех пор, пока не будет убито:
public static void main(String[] args) throws Exception {
try {
while(true) {
Thread.sleep(1000);
}
} catch (NullPointerException ice) {
ice.printStackTrace();
}
}
Запустите приложение, определите его pid, а затем запустите jstack. В Windows вам нужно будет нажать ctrl-break в окне DOS, в котором вы запускаете свой код.
$ jstack
Jstack будет генерировать много выходных данных.
2019-05-13 10:06:17
Full thread dump OpenJDK 64-Bit Server VM (12+33 mixed mode, sharing):
Threads class SMR info:
_java_thread_list=0x00007f8bb2727190, length=10, elements={
0x00007f8bb3807000, 0x00007f8bb2875000, 0x00007f8bb2878000, 0x00007f8bb4000800,
0x00007f8bb300a800, 0x00007f8bb287b800, 0x00007f8bb287f000, 0x00007f8bb28ff800,
0x00007f8bb300b800, 0x00007f8bb3805000
}
"main" #1 prio=5 os_prio=31 cpu=60.42ms elapsed=103.32s tid=0x00007f8bb3807000 nid=0x2503 waiting on condition [0x0000700001a0e000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@12/Native Method)
at com.ericgoebelbecker.stacktraces.StackTrace.main(StackTrace.java:9)
"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=0.08ms elapsed=103.29s tid=0x00007f8bb2875000 nid=0x4603 waiting on condition [0x0000700002123000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@12/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@12/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@12/Reference.java:213)
"Finalizer" #3 daemon prio=8 os_prio=31 cpu=0.13ms elapsed=103.29s tid=0x00007f8bb2878000 nid=0x3903 in Object.wait() [0x0000700002226000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@12/Native Method)
- waiting on <0x000000070ff02770> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@12/ReferenceQueue.java:155)
- locked <0x000000070ff02770> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@12/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@12/Finalizer.java:170)
"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=0.27ms elapsed=103.28s tid=0x00007f8bb4000800 nid=0x3e03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #5 daemon prio=9 os_prio=31 cpu=6.12ms elapsed=103.28s tid=0x00007f8bb300a800 nid=0x5603 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"C1 CompilerThread0" #7 daemon prio=9 os_prio=31 cpu=12.01ms elapsed=103.28s tid=0x00007f8bb287b800 nid=0xa803 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"Sweeper thread" #8 daemon prio=9 os_prio=31 cpu=0.73ms elapsed=103.28s tid=0x00007f8bb287f000 nid=0xa603 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #9 daemon prio=9 os_prio=31 cpu=0.04ms elapsed=103.27s tid=0x00007f8bb28ff800 nid=0xa503 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Common-Cleaner" #10 daemon prio=8 os_prio=31 cpu=0.27ms elapsed=103.27s tid=0x00007f8bb300b800 nid=0xa303 in Object.wait() [0x000070000293b000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@12/Native Method)
- waiting on <0x000000070ff91690> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@12/ReferenceQueue.java:155)
- locked <0x000000070ff91690> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@12/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@12/Thread.java:835)
at jdk.internal.misc.InnocuousThread.run(java.base@12/InnocuousThread.java:134)
"Attach Listener" #11 daemon prio=9 os_prio=31 cpu=0.72ms elapsed=0.10s tid=0x00007f8bb3805000 nid=0x5e03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"VM Thread" os_prio=31 cpu=3.83ms elapsed=103.29s tid=0x00007f8bb2874800 nid=0x3703 runnable
"GC Thread#0" os_prio=31 cpu=0.13ms elapsed=103.31s tid=0x00007f8bb282b800 nid=0x3003 runnable
"G1 Main Marker" os_prio=31 cpu=0.26ms elapsed=103.31s tid=0x00007f8bb2845000 nid=0x3103 runnable
"G1 Conc#0" os_prio=31 cpu=0.04ms elapsed=103.31s tid=0x00007f8bb3810000 nid=0x3303 runnable
"G1 Refine#0" os_prio=31 cpu=0.39ms elapsed=103.31s tid=0x00007f8bb2871000 nid=0x3403 runnable
"G1 Young RemSet Sampling" os_prio=31 cpu=13.60ms elapsed=103.31s tid=0x00007f8bb2872000 nid=0x4d03 runnable
"VM Periodic Task Thread" os_prio=31 cpu=66.44ms elapsed=103.27s tid=0x00007f8bb2900800 nid=0xa403 waiting on condition
JNI global refs: 5, weak refs: 0
Мое приложение выполняло 11 потоков, и stack сгенерировал трассировку стека для всех из них. Первый поток, услужливо названный main, – это тот, который нас интересует. Вы можете видеть, что он спит в режиме ожидания ().
Трассировки стека Java: Ваша дорожная карта
Трассировка стека – это нечто большее, чем просто изображение внутри вашего приложения. Это моментальный снимок момента времени, который включает в себя каждый шаг, который ваш код предпринял, чтобы попасть туда. Нет причин бояться увидеть его в ваших журналах, потому что это подарок от Java, который точно сообщает вам, что произошло. Убедитесь, что вы регистрируете их, когда появляется ошибка, и отправляете их в такой инструмент, как Скалир так что их легко найти.
Теперь, когда вы понимаете, что такое трассировка стека Java и как ее использовать, взгляните на свой код. Вы отбрасываете важную информацию об ошибках и |/исключениях в своем коде? Есть ли место, где вызов Thread.dumpstack() может помочь вам изолировать повторяющуюся ошибку? Возможно, пришло время несколько раз запустить ваше приложение через отладчик с некоторыми стратегически выбранными точками останова.
Оригинал: “https://dev.to/scalyr/java-stack-trace-understanding-it-and-using-it-to-debug-5a3a”