记一次 thread.blocked.count 线程过多的问题排查

2019-08-19 19:56:18 阅读：445 来源： 互联网

标签：count ch qos thread entity 线程 java Logger logback

问题现象：会经常出现block线程过多，但是瞬间又会恢复，因此较困难查询到现场堆栈。jvm.thread.blocked.count >= 50

一、由于现场难以抓取，因此无法用 Jstack 登录机器查询堆栈信息。

二、因为经过调研采用代码的方式，抓取线上block时，线程堆栈信息。

private List<BlockThreadEntity> getBlockThreadList() {
        List<BlockThreadEntity> blockThreadInfoList = new ArrayList<>();
        final ThreadMXBean threadBean = ManagementFactory.getThreadMXBean();
        ThreadInfo[] threadInfos = threadBean.dumpAllThreads(false, false);

        if (threadInfos != null) {
            for (ThreadInfo threadInfo : threadInfos) {
                BlockThreadEntity entity = null;
                if (Thread.State.BLOCKED.equals(threadInfo.getThreadState())) {
                    entity = new BlockThreadEntity();
                    StringBuilder sb = new StringBuilder();
                    StackTraceElement[] stack = threadInfo.getStackTrace();
                    LockInfo lockInfo = threadInfo.getLockInfo();
                    String lockInfoString = null != lockInfo ? lockInfo.getClassName() : "";
                    for (StackTraceElement stackTraceElement : stack) {
                        sb.append("\n" + stackTraceElement.toString());
                    }
                    //记录阻塞线程信息
                    entity.lockInfo = lockInfoString;
                    entity.stackTrace = sb.toString();
                    entity.threadId = String.valueOf(threadInfo.getThreadId());
                    entity.threadName = threadInfo.getThreadName();
                }
                if (entity != null) {
                    blockThreadInfoList.add(entity);
                }
            }
        }
        return blockThreadInfoList;
    }

二、经过一段时间的堆栈信息收集，找到关键的锁信息

com.sankuai.meituan.banma.api.service.tcm.iface.BmTcmRiderApiThriftIface-8-thread-114815]
stacktrace:[
ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:211)
ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:175)
ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103)
ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
com.meituan.scribe.logback.BanmaLogAppender.append(BanmaLogAppender.java:41)
com.meituan.scribe.logback.BanmaLogAppender.append(BanmaLogAppender.java:15)
ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:272)
ch.qos.logback.classic.Logger.callAppenders(Logger.java:259)
ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:441)
ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:395)
ch.qos.logback.classic.Logger.info(Logger.java:599)

lockInfo:[ch.qos.logback.core.spi.LogbackLock]

查看logbck的源码，发现的确是用了 synchronized 锁。

三、进一步源码追踪，发现使用的是同步日志，由于代码中有一个调用量较大的地方，再打印日志，关闭该出日志，问题解决。

四、补充：异步日志。

AsyncAppenderBase 类

BlockingQueue<E> blockingQueue = new ArrayBlockingQueue<E> 使用的是一个队列。

将日志时间放入队列，另一个线程，循环处理。如果队列满了，会丢弃日志。

标签：count,ch,qos,thread,entity,线程,java,Logger,logback
来源： https://www.cnblogs.com/qunan/p/11379213.html

本站声明： 1. iCode9 技术分享网（下文简称本站）提供的所有内容，仅供技术学习、探讨和分享；
2. 关于本站的所有留言、评论、转载及引用，纯属内容发起人的个人观点，与本站观点和立场无关；
3. 关于本站的所有言论和文字，纯属内容发起人的个人观点，与本站观点和立场无关；
4. 本站文章均是网友提供，不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属；如您发现该文章侵犯了您的权益，可联系我们第一时间进行删除；
5. 本站为非盈利性的个人网站，所有内容不会用来进行牟利，也不会利用任何形式的广告来间接获益，纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。

ICode9

记一次 thread.blocked.count 线程过多的问题排查