Не так давно младший разработчик прислал мне запутанную трассировку стека и был очень удивлен, когда я мгновенно понял проблему и указал на необходимые изменения. Честно говоря, у меня было преимущество: ведь это как раз я поместил туда баг. Но все же способность извлекать информацию из трассировки стека, даже запутанной, — серьезный и важный навык.
Трассировка стека, о которой шла речь выше — ClassNotFoundException. Обычно тут ничего сложного: она уже говорит вам все, что нужно знать. Класса нет. Почему его нет — вот ключ к ответу на вопрос, что мы сделали не так. В этом случае, поскольку проект был обфусцирован, ошибка заключалась в том, что этот класс не был исключен из обфускации.
Несмотря на всю ненависть, которую оно вызывает на протяжении многих лет, исключение NullPointerException — одно из моих любимых. Вы мгновенно понимаете, что произошло, и в большинстве случаев стек приводит непосредственно к источнику проблемы. Бывают и спорные случаи, например:
myList.get(offset).invokeMethod();Итак, что же здесь вызвало исключение NullPointerException?
Если вы пользуетесь Java последней версии, он подскажет вам, что довольно круто. Но если мы все еще работаем на Java 11 (или 8), есть несколько вариантов. По крайней мере три или даже четыре, если слегка прищуриться:
myList— очевидный кандидат, но он редко принимает значениеnull, и если так, вы сразу это заметите;offsetможет равнятьсяnull. Допустим, это целочисленный объектInteger, и в этом случае он может принять значениеnullиз-за авто-упаковки. Что также маловероятно.- Наиболее вероятный виновник в данном конкретном случае — возвращаемое значение метода
get(), то есть один из элементов списка имеет значениеnull. - Наконец, сам метод
invokeMethodможет вызвать исключениеNullPointerException. Но это немного обман, так как стек будет глубже.
Таким образом, ничего не зная о коде, мы в существенной степени можем догадаться, что произошло, просто зная тип исключения. Но не всегда это приводит нас непосредственно к ошибке.
Здесь был null
Рассмотренное исключение NullPointerException, вероятно, произошло из-за значения null в списке — если допустить, что вы удостоверились, что по-прежнему не знаете, как он попал в список…
Это нетрудно выяснить. Предположим, список имеет тип ArrayList. В этом случае просто откройте класс ArrayList (допустим, с помощью сочетания клавиш Control-O в IntelliJ) и поместите условную точку останова в метод add(). Так вы протестируете, равно ли значение null, и что прекратит выполнение в точке останова, если кто-то попытается добавить null в список.
Но так не получится поймать все случаи попадания null в список. Это можно сделать с помощью Stream API, addAll() и нескольких других методов. Приятно, что мы можем воспользоваться практически любым из них:
Поскольку addAll() принимает коллекцию, мы можем использовать стандартный метод contains(), чтобы проверить, есть ли у нас нулевой элемент в коллекции, и если да, то остановить выполнение.
Что если “в некоторых случаях” все нормально?
Итак, мы запускаем код — и бинго, он останавливается в точке останова… Но, к сожалению, здесь не тот случай. Эта точка останова связана с другим списком, который мы сейчас не отлаживаем. По-видимому, в этом списке нулевое значение — в порядке вещей.
Поэтому мы нажимаем “Продолжить”, и точка останова срабатывает снова, и снова, и снова. Каждый раз — из-за неправильного списка. Зачастую именно в такие моменты разработчики начинают громко ругаться и ругать отладчики в тоске по старым-добрым журналам.
Есть несколько способов обойти эту проблему. Идеальный вариант — избегать этого конкретного списка. Если у вас есть способ распознать этот список, например, глобальный экземпляр или первый элемент с определенным значением, можно просто преобразовать исходную условную точку останова. К примеру, в рассматриваемом случае мы предполагаем, что первый элемент в списке null_is_OK равен 77, и тогда это условие позволит обойти проблему:
Не идеально, но сработает как обходной путь, если проблема достаточно хорошо локализована.
Вложенная трассировка стека
Вот она, одна из “болей” современных фреймворков. Фреймворк улавливает исключение и распространяет его, заключая в свое собственное исключение. Смыть, повторить. В итоге получается матрешка из трассировок стека.
Просеивание всех этих стеков и поиск того, что имеет значение, часто является огромной частью боли. Особенно в таких фреймворках, как Spring, где стеки становятся особенно длинными и трудночитаемыми из-за прокси-кода.
Например:
javax.ws.rs.ProcessingException: RESTEASY004655: Unable to invoke request: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8443 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused (Connection refused)
at org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient4Engine.invoke(ApacheHttpClient4Engine.java:328)
at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:443)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:149)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invoke(ClientInvoker.java:112)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientProxy.invoke(ClientProxy.java:76)
at com.sun.proxy.$Proxy307.grantToken(Unknown Source)
at org.keycloak.admin.client.token.TokenManager.grantToken(TokenManager.java:90)
at org.keycloak.admin.client.token.TokenManager.getAccessToken(TokenManager.java:70)
at org.keycloak.admin.client.token.TokenManager.getAccessTokenString(TokenManager.java:65)
at org.keycloak.admin.client.resource.BearerAuthFilter.filter(BearerAuthFilter.java:52)
at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.filterRequest(ClientInvocation.java:579)
at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:440)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:149)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invoke(ClientInvoker.java:112)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientProxy.invoke(ClientProxy.java:76)
at com.sun.proxy.$Proxy315.toRepresentation(Unknown Source)
at io.athena_tech.server.security.keycloak.KeycloakRealmService.lambda$doesLightrunRealmExist$0(KeycloakRealmService.java:124)
at io.athena_tech.server.security.keycloak.KeycloakApi.getWithAdmin(KeycloakApi.java:35)
at io.athena_tech.server.security.keycloak.KeycloakRealmService.doesLightrunRealmExist(KeycloakRealmService.java:122)
at io.athena_tech.server.security.keycloak.KeycloakRealmService$$FastClassBySpringCGLIB$$9e16800d.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:771)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:366)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
at io.athena_tech.server.security.keycloak.KeycloakRealmService$$EnhancerBySpringCGLIB$$7eca0d51.doesLightrunRealmExist(<generated>)
at io.athena_tech.server.service.client.InitKeycloakService.initDefaultCompanies(InitKeycloakService.java:146)
at io.athena_tech.server.service.client.InitKeycloakService$$FastClassBySpringCGLIB$$35f06991.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:771)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.aspectj.AspectJAfterThrowingAdvice.invoke(AspectJAfterThrowingAdvice.java:62)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
at io.athena_tech.server.service.client.InitKeycloakService$$EnhancerBySpringCGLIB$$5ae1a459.initDefaultCompanies(<generated>)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:305)
at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:190)
at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:153)
at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:403)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:360)
at org.springframework.boot.context.event.EventPublishingRunListener.running(EventPublishingRunListener.java:103)
at org.springframework.boot.SpringApplicationRunListeners.running(SpringApplicationRunListeners.java:77)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:330)
at io.athena_tech.server.AthenaServerApp.main(AthenaServerApp.java:64)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)
Caused by: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8443 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused (Connection refused)
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient4Engine.invoke(ApacheHttpClient4Engine.java:323)
... 64 common frames omitted
Caused by: java.net.ConnectException: Connection refused (Connection refused)
at java.base/java.net.PlainSocketImpl.socketConnect(Native Method)
at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:403)
at java.base/java.net.Socket.connect(Socket.java:609)
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
... 74 common frames omittedМожет кто-нибудь сказать, что я тут сделал не так при попытке запустить сервер локально?
Попробуем разбить эту стену текста, начиная с самого нижнего исключения, которое обычно и бывает основной причиной:
Caused by: java.net.ConnectException: Connection refused (Connection refused)
at java.base/java.net.PlainSocketImpl.socketConnect(Native Method)
at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:403)
at java.base/java.net.Socket.connect(Socket.java:609)
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)Налицо проблема с подключением. Соединение отклонено, что означает — наш сервер пытается подключиться к какому-то еще серверу, но терпит неудачу.
Так мы получили некоторую базовую информацию, но ничего больше.
Перейдем на одно исключение выше и взглянем на второй блок. Поскольку он большой, я сосредоточусь только на крайней части исключения:
Caused by: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8443 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused (Connection refused)
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)И снова ничего стоящего. Это код подключения к Apache. Но никакой информации о том, кто его спровоцировал и почему.
Итак, мы вернулись на самый верх, что менее типично. И здесь мы, наконец, находим ответ:
javax.ws.rs.ProcessingException: RESTEASY004655: Unable to invoke request: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8443 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused (Connection refused)
at org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient4Engine.invoke(ApacheHttpClient4Engine.java:328)
at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:443)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:149)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invoke(ClientInvoker.java:112)
at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientProxy.invoke(ClientProxy.java:76)
at com.sun.proxy.$Proxy307.grantToken(Unknown Source)
at org.keycloak.admin.client.token.TokenManager.grantToken(TokenManager.java:90)
at org.keycloak.admin.client.token.TokenManager.getAccessToken(TokenManager.java:70)
at org.keycloak.admin.client.token.TokenManager.getAccessTokenString(TokenManager.java:65)
at org.keycloak.admin.client.resource.BearerAuthFilter.filter(BearerAuthFilter.java:52)Если посмотреть немного ниже, вы увидите пакеты org.keycloak. По сути, это означает, что я забыл запустить keycloak перед запуском сервера. Причина была хорошо скрыта в стеке и ее обнаружение требовало знания предметной области (мы пользуемся keycloak).
Просто продолжайте читать стек — ответ обычно находится где-то с краю (внизу или вверху). Не сдавайтесь, если что-то проясняется не сразу.
TL;DR
Как правило, причину исключения, которое мы видим в журнале или получаем от пользователя, можно выяснить, просто поглядев на трассировку стека и копнув глубже. Само собой, держите в голове вложенные исключения и другие подобные проблемы.
Отладчик все еще может сослужить хорошую службу при выяснении основной причины исключения, которое отражено в стеке. Для сужения круга подозреваемых можно воспользоваться такой функциональностью, как условные точки останова. Как ни странно, здесь мы ни разу не коснулись точек останова применительно к исключениям. На мой взгляд, они ценны по-своему, но когда у нас есть стек, мы уже знаем (примерно), что произошло и где.
Читайте также:
- Отладка для абсолютных новичков
- Как прокачать навык отладки
- Как отладка поможет вам стать лучшим разработчиком
Читайте нас в Telegram, VK и Яндекс.Дзен
Перевод статьи Shai Almog: Understanding Stack Traces and Debugging them Further
