记一次线上服务请求阻塞问题排查

问题

有个项目有一个服务节点出了问题，收到的请求一直没有返回，看日志是有收到请求，但是在接收到请求之后，没有下一步的处理（日志）了。

内存

由于该项目早前出现过一次内存溢出的情况，所以第一步先看下内存情况，只使用了20%，通过jmap -heap 进程ID看到新生代和老年代都只有70%多，并且没有在快速增长。

CPU

通过top命令看到系统CPU使用率是27.3%，服务进程是2.0%。
通过ps -mp 进程ID -o THREAD,tid,time，也没有看到服务里有哪个线程CPU特别高。

死锁检查

通过jstack 进程ID > jstack.log导出线程列表，发现没有死锁，但是线程基本上都卡在日志打印上。

"http-nio-8080-exec-199" #727 daemon prio=5 os_prio=0 tid=0x00007f766809b000 nid=0x3c0 waiting for monitor entry [0x00007f75e90c8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.logging.log4j.core.appender.OutputStreamManager.writeBytes(OutputStreamManager.java:359)
    - waiting to lock <0x00000000814db020> (a org.apache.logging.log4j.core.appender.OutputStreamManager)
    at org.apache.logging.log4j.core.layout.TextEncoderHelper.writeEncodedText(TextEncoderHelper.java:96)

I/O

既然线程都卡在日志打印上，那是不是I/0问题？
通过iostat -x 1 10看到%util是100%，说明产生的I/O请求太多，I/O系统已经满负荷，该磁盘可能存在瓶颈。
那是不是log日志打印的太多了，进入服务器查看服务日志，发现服务开启了DEBUG日志，大量的DEBUG日志，且很多日志单行特别大，正常情况下线上是不应该打开DEBUG日志的。

原因

项目每次收到请求时，都会DEBUG打印请求日志，日志里包含了详细的header、request body、response body等信息，日志很大，同时mybatis也会DEBUG打印每次数据库操作信息，加上其他日志，项目有大量DEBUG日志，在并发比较高或者请求数据比较大的时候，出现了I/O问题，后续收到的每个请求在打印日志时，都被阻塞了。
同时项目仍在向注册中心Eureka发送心跳（发送心跳时不会打印日志），所以项目仍会持续收到业务请求。

处理方式

线上关闭DEBUG日志，后续持续观察是否还会复现。