一次鞭辟入里的 Log4j2 日志输出阻塞问题的定位 问题现象
线上某个应用的某个实例突然出现某些次请求服务响应极慢的情况，有几次请求超过 60s 才返回，并且通过日志发现，服务线程并没有做什么很重的操作。这种情况断断续续持续了半小时左右。
核心问题定位由于半小时后，服务实例恢复正常，并且出现请求极慢的次数并不太多，没有能及时打印出现问题的时候线程堆栈采集相关信息。但是，我们有自己的法宝，JFR（关于 JFR，请参考我的另一系列JFR全解）。
JFR 非常适合用来事后复盘定位问题，并且配置得当的话，性能损耗极小，并且不像 APM 系统一样需要额外的采集以及需要统一的服务进程进行整合展现。我们随用随取即可，但是 JFR 面向的是单进程的问题定位，找到问题进程，定位跨进程业务问题链路追踪还是需要 APM 系统的。
我们通过如下命令采集对应时间段的 JFR：
jcmd 进程pid JFR.dump begin=2021-07-04T17:30:00.000Z end=2021-07-04T18:30:00.000Z我们选择的时间跨度比出问题的时间跨度大一些，这样保证底层问题出现的时候也被采集写入这个 dump 文件。
对于历史某些请求响应慢，我一般按照如下流程去看：
是否有 STW（Stop-the-world，参考我的另一篇文章：JVM相关 - SafePoint 与 Stop The World 全解）:
是否有 GC 导致的长时间 STW
是否有其他原因导致进程所有线程进入 safepoint 导致 STW
是否 IO 花了太长时间，例如调用其他微服务，访问各种存储（硬盘，数据库，缓存等等）
是否在某些锁上面阻塞太长时间？
是否 CPU 占用过高，哪些线程导致的？
接下来我们来详细分析，首先是 GC，从下图看，并没有能严重影响线程 STW 很长时间的：
然后查看 safepoint 相关，发现也没有什么影响：
接着，我们查看 IO 相关的事件，也并没有发现业务相关的阻塞读：
然后，我们查看是否在某些锁上面阻塞太长时间，终于发现异常：
通过堆栈，我们发现是** log4j2 打印日志卡住了**。
问题分析 1. Java Monitor Blocked 的 Monitor Address 对于同一个对象也是会改变的首先，对于 Java Monitor Blocked 这个事件，我们可以通过 Monitor Address 来判断是否是同一个锁。例如这里我们发现这些线程都是阻塞在 FFFF 4C09 3188 这个地址的对象，这个地址是基于对象在 Java 堆中的相对地址得出的。
但是对于同一个对象，这个地址并不会是不变的，在每次 GC 扫描整理到这个对象对象的时候，如果有回收内存，一般这个地址就会改变。由于我们使用的是 G1，所以并不是每次 GC 都会扫描到这个对象，但是如果地址发生改变，一定是因为发生了 GC
2. log4j2 异步日志原理简介在我们的应用配置中，采用的日志框架是 log4j2，采用的配置是异步日志配置。这里简单说一下 Log4j2 异步日志的原理：Log4j2 异步日志基于高性能数据结构 Disruptor，Disruptor 是一个环形 buffer，做了很多性能优化（具体原理可以参考我的另一系列：高并发数据结构（disruptor）），Log4j2 对此的应用如下所示：