记一次Sentry-Java未上报异常的详细排查过程

作者: 天草二十六_简村人 | 来源:发表于2021-09-15 09:35 被阅读0次

记一次Sentry-Java未上报异常的详细排查过程
netty线上问题排查
电脑直连路由器无法登陆WEB界面
AP无法上线AC
WrapHeightListView 测量不准确？
无线卡问题
JVM问题排查实战系列
排查WriteAbortedException异常过程
做JAVA开发的同学一定遇到过的爆表问题，看这里解决
DHCP获取不上地址

一、背景

1. 当sentry.debug=true开关打开时，应用在启动的过程中，会输出调试信息：

INFO: Initializing SDK with DSN: 'http://d644bf38fdd64adeab89ed330f2815d3@192.168.10.109:9000/68'
INFO: No outbox dir path is defined in options.
INFO: GlobalHubMode: 'false'
DEBUG: UncaughtExceptionHandlerIntegration enabled: true
DEBUG: UncaughtExceptionHandlerIntegration installed.

可以说明，你的程序是加载并初始化了Sentry，而且连接DSN地址是成功的。

2.当sentry.debug=true开关打开时，每当打印error日志时，同时也会输出上报成功或失败的信息：

2021-09-14 17:57:47.737 ERROR ..................................
..........................................................................................
DEBUG: Capturing event: 47f54cf7dc914c469ab543573dd43e3b
INFO: Session is null on scope.withSession
DEBUG: Envelope sent successfully.
DEBUG: Envelope flushed

如果看到了上述调试日志，说明也是上报成功了的。

而本文的案例遇到的情况是，debug开启了，但是只有输出error日志，并无后面的sentry调试日志。
还有一个背景是：对接的服务有几个会输出，有几个是不会输出调试日志，当然也没有上报错误。

开发在本地环境调试，正确无误，但是测试在测试环境就是没有调试日志，也不会上报错误。

二、排查思路

1. 因为更换了配置文件，会不会是配置不对，或者说程序加载的配置对不上。

验证方法：我在本地程序中读取测试环境的配置，然后自测，结果是会打印调试日志，并上报错误。
说明配置是没问题的。

2. 应用程序jar的版本和本地的版本是不是同一个？

验证方法：由于不能直接对测试环境断点调试，所以把测试环境的jar下载到本地，然后手动启动，当然还是读取测试环境的配置。

java -jar -DCONFIG_SERVICE_HOST=192.168.5.87 -DCONFIG_SERVICE_ENABLED=true user-service.jar

结果也是没有打印调试日志，更不要说上报错误了。

结论是：同样的程序，同样的配置，多次执行却出现了随机的诡异结果。

3. 期间，我还本地打包，然后对jar包手动启动。

验证的思路是：都是jar包启动，都是一个配置。我的验证结果是：本地也出现了偶尔没有打印调试日志，也没有上报到sentry server。

还走过不少弯路：修改dsn，故意写错；或者不填写dsn。总是怀疑dsn，确实走了不必要的弯路。

需要重新调整一下思路，程序是否加载了io.sentry.logback.SentryAppender，因为它是会实现ch.qos.logback.core.UnsynchronizedAppenderBase#append。（这里需要理解的话，建议看另外一篇文https://www.jianshu.com/p/07f44a3e3607）

后面的排查思路是：

slf4j在log.error的时候是否会触发io.sentry.logback.SentryAppender.append()
logger除了默认的ch.qos.logback.core.ConsoleAppender，是否还有io.sentry.logback.SentryAppender
spring 容器中是否初始化了类SentryLogbackInitializer 和 SentryLogbackAppenderAutoConfig

三、排查手段

1. arthas

具体的使用办法见官网。
我这里因为是要看程序是否触发了哪些代码，所以为使用watch , trace等命令即可。

trace命令，这里并没有看到SentryAppender的任何代码

[arthas@592433]$ trace ch.qos.logback.core.UnsynchronizedAppenderBase doAppend -n 10
Press Q or Ctrl+C to abort.
Affect(class count: 6 , method count: 1) cost in 303 ms, listenerId: 11
`---ts=2021-09-14 15:33:15;thread_name=http-nio-7501-exec-9;id=3e;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@4230126
    `---[1.941664ms] ch.qos.logback.core.UnsynchronizedAppenderBase:doAppend()
        +---[0.073921ms] ch.qos.logback.core.UnsynchronizedAppenderBase:getFilterChainDecision() #79
        `---[1.516021ms] ch.qos.logback.core.UnsynchronizedAppenderBase:append() #84

watch命令，对比发现，能够正常上报错误的程序是有两个UnsynchronizedAppenderBase的实现类，SENTRY_APPENDER和CONSOLE。

[arthas@605087]$ watch ch.qos.logback.core.UnsynchronizedAppenderBase doAppend 'target' -n 10
Press Q or Ctrl+C to abort.
Affect(class count: 4 , method count: 1) cost in 303 ms, listenerId: 1
method=ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend location=AtExit
ts=2021-09-14 15:39:24; [cost=4.536136ms] result=@ConsoleAppender[
    target=@ConsoleTarget[System.out],
    withJansi=@Boolean[false],
    WindowsAnsiOutputStream_CLASS_NAME=@String[org.fusesource.jansi.WindowsAnsiOutputStream],
    encoder=@PatternLayoutEncoder[ch.qos.logback.classic.encoder.PatternLayoutEncoder@5a8d0801],
    lock=@ReentrantLock[java.util.concurrent.locks.ReentrantLock@124d2b02[Unlocked]],
    outputStream=@[ch.qos.logback.core.joran.spi.ConsoleTarget$1@4171029d],
    immediateFlush=@Boolean[true],
    started=@Boolean[true],
    guard=@ThreadLocal[java.lang.ThreadLocal@5405cbb0],
    name=@String[CONSOLE],
    fai=@FilterAttachableImpl[ch.qos.logback.core.spi.FilterAttachableImpl@667a0c31],
    statusRepeatCount=@Integer[0],
    exceptionCount=@Integer[0],
    ALLOWED_REPEATS=@Integer[3],
    noContextWarning=@Integer[0],
    context=@LoggerContext[ch.qos.logback.classic.LoggerContext[default]],
    declaredOrigin=@ConsoleAppender[ch.qos.logback.core.ConsoleAppender[CONSOLE]],
]
method=ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend location=AtExit
ts=2021-09-14 15:39:24; [cost=29.97918ms] result=@SentryAppender[
    options=@SentryOptions[io.sentry.SentryOptions@7f3eebee],
    transportFactory=null,
    minimumBreadcrumbLevel=@Level[INFO],
    minimumEventLevel=@Level[ERROR],
    started=@Boolean[true],
    guard=@ThreadLocal[java.lang.ThreadLocal@499ceacb],
    name=@String[SENTRY_APPENDER],
    fai=@FilterAttachableImpl[ch.qos.logback.core.spi.FilterAttachableImpl@63afa9da],
    statusRepeatCount=@Integer[0],
    exceptionCount=@Integer[0],
    ALLOWED_REPEATS=@Integer[3],
    noContextWarning=@Integer[0],
    context=@LoggerContext[ch.qos.logback.classic.LoggerContext[default]],
    declaredOrigin=@SentryAppender[io.sentry.logback.SentryAppender[SENTRY_APPENDER]],
]

logger命令

[arthas@629531]$ logger
 name                  ROOT                                                                                                         
 class                 ch.qos.logback.classic.Logger                                                                                
 classLoader           org.springframework.boot.loader.LaunchedURLClassLoader@2d3fcdbd                                              
 classLoaderHash       2d3fcdbd                                                                                                     
 level                 WARN                                                                                                         
 effectiveLevel        WARN                                                                                                         
 additivity            true                                                                                                         
 codeSource            jar:file:/xxx-service.jar!/BOOT-INF/lib/logback-classic-1.2.3.jar!/             
 appenders             name            CONSOLE                                                                                      
                       class           ch.qos.logback.core.ConsoleAppender                                                          
                       classLoader     org.springframework.boot.loader.LaunchedURLClassLoader@2d3fcdbd                              
                       classLoaderHash 2d3fcdbd                                                                                     
                       target          System.out

2. spring boot beans

检索sentryLogbackInitializer 和 sentryLogbackAppenderAutoConfig

"sentryLogbackInitializer":{"aliases":[],"scope":"singleton","type":"com.common.events.SentryLogbackInitializer","resource":"class path resource [com/config/SentryLogbackAppenderAutoConfig.class]","dependencies":["sentryProperties"]}

"sentryLogbackAppenderAutoConfig":{"aliases":[],"scope":"singleton","type":"com.config.SentryLogbackAppenderAutoConfig$$EnhancerBySpringCGLIB$$c67b2f41","resource":"file [/opt/xxx-service/target/classes/com/config/SentryLogbackAppenderAutoConfig.class]","dependencies":[]}

"sentryConfig":{"aliases":[],"scope":"singleton","type":"com.config.SentryConfig$$EnhancerBySpringCGLIB$$e8c663aa","resource":"file [/opt/xxx-service-sync/target/classes/com/config/SentryConfig.class]","dependencies":["sentryProperties"]}

3. 远程断点

//启动命令中增加-agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=5005

四、结论

程序之所以没上报错误，是因为没有初始化必需的类 SentryLogbackInitializer 和 SentryLogbackAppenderAutoConfig。
@ConditionalOnBean(SentryProperties.class) 重点注意这行代码，但是SentryProperties是什么时候加载到spring容器里呢？
依赖于类SentryConfiguration的注解@EnableConfigurationProperties，这就要求SentryConfiguration在SentryLogbackAppenderAutoConfiguration前面进行加载到容器里。
同时也是我们本次bug的根源。

import ch.qos.logback.classic.LoggerContext;
import io.sentry.logback.SentryAppender;
import org.springframework.boot.autoconfigure.condition.ConditionalOnBean;
import org.springframework.boot.autoconfigure.condition.ConditionalOnClass;
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
 
/**
 * Auto-configures {@link SentryAppender}.
 */
@Configuration
@ConditionalOnClass({LoggerContext.class, SentryAppender.class})
@ConditionalOnProperty(name = "sentry.logging.enabled", havingValue = "true", matchIfMissing = true)
@ConditionalOnBean(SentryProperties.class)
public class SentryLogbackAppenderAutoConfiguration {
 
    @Bean
    public SentryLogbackInitializer sentryLogbackInitializer(
            final SentryProperties sentryProperties) {
        return new SentryLogbackInitializer(sentryProperties);
    }
}

/**
 * sentry配置初始化.
 *
 */
@EnableConfigurationProperties(SentryProperties.class)
@ConditionalOnClass({HandlerExceptionResolver.class, SentryExceptionResolver.class})
@ConditionalOnWebApplication
@ConditionalOnProperty(name = "sentry.enabled", havingValue = "true", matchIfMissing = true)
@Configuration
public class SentryConfiguration {

这里再贴出来类SentryProperties的详情，这里没有写@Component, 也没有@Configuration。所以它加载到容器是依赖于类SentryConfiguration的。

import lombok.Data;
import org.springframework.boot.context.properties.ConfigurationProperties;
 
import java.util.LinkedHashMap;
import java.util.Map;
 
/**
 * sentry.property
 *
 */
@Data
@ConfigurationProperties("sentry")
public class SentryProperties {

五、修改办法

1、类SentryLogbackAppenderAutoConfiguration删掉注解行@ConditionalOnBean(SentryProperties.class)

2、类SentryConfiguration删掉注解行@EnableConfigurationProperties(SentryProperties.class)

3、类SentryProperties增加注解@Configuration

@Data
@Configuration // 增加该注解
@ConfigurationProperties("sentry")
public class SentryProperties {

记一次Sentry-Java未上报异常的详细排查过程
一、背景 1. 当sentry.debug=true开关打开时，应用在启动的过程中，会输出调试信息：可以说明，你...
netty线上问题排查
记一次压测异常排查
电脑直连路由器无法登陆WEB界面
【详细故障排查】如需了解更加详细的排查过程，请点击我进入
AP无法上线AC
【免费视频】RAP无法上线排查【详细故障排查】如需了解更加详细的排查过程，请点击我进入
WrapHeightListView 测量不准确？
问题本文没有特别的知识点，仅仅是记一次 ui 异常的问题排查和解决过程。如果你也遇到过 WrapHeightLi...
无线卡问题
【免费视频】无线卡问题【详细故障排查】如需了解更加详细的排查过程，请点击我进入
JVM问题排查实战系列
JVM问题排查实战记一次频繁FGC的简单排查一次JVM GC长暂停的排查过程如何使用MAT进行内存泄露分析
排查WriteAbortedException异常过程
昨天突然收到运维信息说线上写日志太猛，磁盘饱满了，然后应用接口超时报警.....一系列问题突然涌现出来.....
做JAVA开发的同学一定遇到过的爆表问题，看这里解决
记一次Java线上服务器CPU过载问题的排查过程，详解排查过程中用到的Java性能监测工具：jvisualvm、j...
DHCP获取不上地址
【免费视频】DHCP获取不上地址【详细故障排查】如需了解更加详细的排查过程，请点击我进入

记一次Sentry-Java未上报异常的详细排查过程

一、背景

1. 当sentry.debug=true开关打开时，应用在启动的过程中，会输出调试信息：

2.当sentry.debug=true开关打开时，每当打印error日志时，同时也会输出上报成功或失败的信息：

二、排查思路

1. 因为更换了配置文件，会不会是配置不对，或者说程序加载的配置对不上。

2. 应用程序jar的版本和本地的版本是不是同一个？

3. 期间，我还本地打包，然后对jar包手动启动。

三、排查手段

1. arthas

2. spring boot beans

3. 远程断点

四、结论

五、修改办法

1、类SentryLogbackAppenderAutoConfiguration删掉注解行@ConditionalOnBean(SentryProperties.class)

2、类SentryConfiguration删掉注解行@EnableConfigurationProperties(SentryProperties.class)

3、类SentryProperties增加注解@Configuration

相关文章

记一次Sentry-Java未上报异常的详细排查过程

netty线上问题排查

电脑直连路由器无法登陆WEB界面

AP无法上线AC

WrapHeightListView 测量不准确？

无线卡问题

JVM问题排查实战系列

排查WriteAbortedException异常过程

做JAVA开发的同学一定遇到过的爆表问题，看这里解决

DHCP获取不上地址

网友评论

延伸阅读

深度阅读

栏目导航

热点阅读