诊断服务端报错问题

更新时间:
复制 MD 格式

网页抛错是互联网应用最常见的问题之一,但其错因分析是一个难点。为应用安装ARMS探针后,就能在不改动应用代码的情况下,借助ARMS应用监控的异常自动捕捉、收集、统计和溯源等功能,准确定位应用中所有异常并进行线上诊断。

问题描述

网页抛错,尤其是5xx错误是互联网应用最常见的问题之一。5xx错误通常发生于服务端。服务端是业务逻辑最复杂,也是整条网络请求链路中最容易出错、出了错之后最难诊断原因的地方。运维工程师或研发工程师往往需要登录机器查看日志来定位问题。

示例:常见的Java应用错误日志


2018-03-19 20:34:22,890 ERROR [io.undertow.request] (default task-84) UT005023: Exception handling request to /plan-manage.htm:
java.lang.IllegalStateException: UT000010: Session not found wFcTlKtkzPiwMyNtBTFv48jU
	at io.undertow.server.session.InMemorySessionManager$SessionImpl.getAttribute(InMemorySessionManager.java:353) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.spec.HttpSessionImpl.getAttribute(HttpSessionImpl.java:121) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at org.springframework.security.web.context.HttpSessionSecurityContextRepository$SaveToSessionResponseWrapper.saveContext(HttpSessionSecurityContextRepository.java:323) [spring-security-web-3.2.5.RELEASE.jar:3.2.5.RELEASE]
	at org.springframework.security.web.context.HttpSessionSecurityContextRepository.saveContext(HttpSessionSecurityContextRepository.java:117) [spring-security-web-3.2.5.RELEASE.jar:3.2.5.RELEASE]
	at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:93) [spring-security-web-3.2.5.RELEASE.jar:3.2.5.RELEASE]
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.5.RELEASE.jar:3.2.5.RELEASE]
	at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) [spring-security-web-3.2.5.RELEASE.jar:3.2.5.RELEASE]
	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) [spring-security-web-3.2.5.RELEASE.jar:3.2.5.RELEASE]
	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) [spring-web-4.0.6.RELEASE.jar:4.0.6.RELEASE]
	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) [spring-web-4.0.6.RELEASE.jar:4.0.6.RELEASE]
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88) [spring-web-4.0.6.RELEASE.jar:4.0.6.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.0.6.RELEASE.jar:4.0.6.RELEASE]
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:85) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:61) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:56) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:45) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:63) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:70) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:261) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:247) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:76) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:166) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:197) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:759) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_45]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_45]
	at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_45]

对于逻辑不太复杂、上线时间不长的应用来说,登录机器查看日志的方式能够解决大部分网站抛错的问题。但在以下场景中,传统的问题诊断方式往往没有用武之地。

  • 在一个分布式应用集群中,需知道某一类错误的发生时间和频率。

  • 某系统已运行了很长时间,但是不想关心遗留的异常,只想知道今天和昨天相比、发布后和发布前相比多了哪些异常。

  • 查看一个异常对应的Web请求和相关参数。

  • 客服人员提供了一个用户下单失败的订单号,分析该用户下单失败的原因。

解决方案

为应用安装ARMS探针后,即可在不改动应用代码的情况下,利用ARMS应用监控的异常自动捕捉、收集、统计和溯源等能力,全面掌握应用的各种错误信息。

步骤一:安装ARMS探针

为应用安装ARMS探针后,才能对应用进行全方位监控。请根据实际需求选择一种方式来安装探针。具体操作,请参见应用监控接入概述。

步骤二:查看关于应用异常的统计信息

为应用安装ARMS探针后,ARMS会收集和展示选定时间内应用的总请求量、平均响应时间、错误数、实时实例数、FullGC次数、慢SQL次数、异常次数和慢调用次数,以及这些指标和上一天的环比、上周的同比升降幅度。请按以下步骤查看应用异常的统计信息。

  1. 登录ARMS控制台,在左侧导航栏选择应用监控 > 应用列表。

  2. 在应用列表页面顶部选择目标地域,然后单击目标应用名称。

    说明

    语言列的图标含义如下:

    Java图标:接入应用监控的Java应用。

    image:接入应用监控的Golang应用。

    image:接入应用监控的Python应用。

    -:接入可观测链路 OpenTelemetry 版的应用。

  3. 在应用概览页面的概览分析页签下方,查看异常的总数、周同比和日同比数据。

  4. 滑动页面至概览分析页签底部的统计分析区域的异常类型,查看各类型异常出现的次数。

    各类型异常出现的次数

  5. 在左侧导航栏,单击应用详情,然后在页面右侧单击异常分析页签,查看异常统计图、错误数、异常堆栈等。

步骤三:诊断异常出现的原因

掌握应用异常的统计信息还不足以诊断异常出现的原因。虽然日志中异常堆栈包含调用的代码片段,但并不包含这次调用的完整上下游信息和请求参数。ARMS探针采用了字节码增强技术,让您能够以很小的性能消耗捕获异常上下游的完整调用快照,进而找出导致异常出现的具体原因。

  1. 在异常分析页签下,找到要诊断的异常类型,在其右侧操作列,单击调用链查询。

    调用链查询页签下显示与该异常类型相关的调用链路信息。

  2. 在调用链查询页签下,单击某个错误调用的TraceId。

    说明

    如何查找目标调用链路,请参见调用链路查询。

    接口快照页签

  3. 在弹出的页面,查看异常的调用链路信息,在详情列,单击放大镜图标,查看调用的方法栈,从而获得异常的上下文信息。

    方法栈信息显示调用链路总耗时 58947ms,关键调用包括:

    • Tomcat Servlet Process(58947ms)

    • sun.net.www.protocol.http.HttpURLConnection.getInputStream()(行号 1476,21ms,异常信息:java.io.IOException: Server)

    • org.apache.http.impl.client.CloseableHttpClient.execute(...)(行号 81,104ms)

    • org.apache.http.protocol.HttpRequestExecutor.execute(...)(行号 118,93ms)

    • com.alibaba.arms.console.service.impl.ArmsContextServiceImpl.clear()(行号 79,0ms)

    操作至此,您已发现了应用异常的原因,这将有效地帮助您进行下一步的代码优化工作。您还可以返回调用链查询页签,查看列表中其他异常,逐一解决。