1，现象描述
[2022-01-03 08:56:55.141] [WARN] [NettyServerWorker-4-5] [c.a.d.c.t.s.AbortPolicyWithReport:rejectedExecution:64] [DUBBO] Thread pool is EXHAUSTED! Thread Name: DubboServerHandler-10.10.137.103:20881, Pool Si ze: 1200 (active: 1200, core: 1200, max: 1200, largest: 1200), Task: 44747608 (completed: 44746408), Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://10.10.137.103:20881! , dubbo version: 2.6.9, current host: 10.10.1.1 [2022-01-03 08:56:55.141] [WARN] [NettyServerWorker-4-4] [c.a.d.c.t.s.AbortPolicyWithReport:rejectedExecution:64] [DUBBO] Thread pool is EXHAUSTED! Thread Name: DubboServerHandler-10.10.137.103:20881, Pool Si ze: 1200 (active: 1200, core: 1200, max: 1200, largest: 1200), Task: 44747608 (completed: 44746408), Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://10.10.137.103:20881! , dubbo version: 2.6.9, current host: 10.10.1.1
2，处理过程
1）最先开始发现时间是12月21号，原来线程池是1000，先从1000改成了1200
threadpool="fixed" threads="${server.threads}"
dubbo的线程策略是fixed，就是固定的大小，简单介绍如下
fixed --固定线程数量
cached --线程空闲一分钟会被回收，当新请求到来时会创建新线程
limited--线程个数随着任务增加而增加，但不会超过最大阈值。空闲线程不会被回收
eager --当所有核心线程数都处于忙碌状态时，优先创建新线程执行任务
2）系统再次出现是12月28，12月29日的
本以为改了线程池的大小，问题就能解决了，没想到后续连续出现两次，严重影响业务了，不得不解决了。
3）最开始的想法是，线程池占用满了，应该是有大量线程在使用，就排查项目日志中都有哪些方法在大量占用
通过命令查询使用方法 awk '{print $21}' amp-service.debug-2021-12-27.17.log |sort -n -k 1 -r | uniq -c
查询到有很多方法调用，多次，有超过一万次以上的，具体方法不再列出。
4）在12月29号晚上发了一版，12月30的时候基本没有出现问题，以为万事大吉了。
5） 1月3号时，业务反馈还是有错误情况，观察服务器，还是有Thread pool is EXHAUSTED! 出现的情况。
最开始问题方向：1，应该有大量线程调用，检查调用方
1）web端调用，查询到某些url返回结果错误，这个也是会引起报错。---待后续优化
2）service，job定时任务调度，这个有很多使用方，不太好排查，只能查询servcie中的调用日志，这个上面已经优化了一部分
3） 本身service，调用外部报错，发现调用http接口有超时情况，60秒超时 ---待后续优化
4）用tcpdump 查询，这个命令不太会，最后也没有收集成
这些基本都不是最主要的原因，都是可能会导致线程池满的。
6，1月4号，无疑中发现服务器有一些Dubbo_JStack.log.2021-12-09_17:14:50的文件
查询才知道，dubbo，线程拒绝的策略之后，会自动记录dubbo-stack的信息 ，参考 https://tech.souyunku.com/?p=33183
pupublic class AbortPolicyWithReport extends ThreadPoolExecutor.AbortPolicy {
protected static final Logger logger = LoggerFactory.getLogger(AbortPolicyWithReport.class);
private final String threadName;
private final URL url;
private static volatile long lastPrintTime = 0;
private static Semaphore guard = new Semaphore(1);
public AbortPolicyWithReport(String threadName, URL url) {
this.threadName = threadName;
this.url = url;
}
@Override
public void rejectedExecution(Runnable r, ThreadPoolExecutor e) {
String msg = String.format("Thread pool is EXHAUSTED!" +
" Thread Name: %s, Pool Size: %d (active: %d, core: %d, max: %d, largest: %d), Task: %d (completed: %d)," +
" Executor status:(isShutdown:%s, isTerminated:%s, isTerminating:%s), in %s://%s:%d!",
threadName, e.getPoolSize(), e.getActiveCount(), e.getCorePoolSize(), e.getMaximumPoolSize(), e.getLargestPoolSize(),
e.getTaskCount(), e.getCompletedTaskCount(), e.isShutdown(), e.isTerminated(), e.isTerminating(),
url.getProtocol(), url.getIp(), url.getPort());
logger.warn(msg);
dumpJStack();
throw new RejectedExecutionException(msg);
}
private void dumpJStack() {
long now = System.currentTimeMillis();
//dump every 10 minutes
//每 10 分钟，只打印一次。
if (now - lastPrintTime < 10 * 60 * 1000) {
return;
}
//获得信号量。保证，同一时间，有且仅有一个线程执行打印。
if (!guard.tryAcquire()) {
return;
}
//// 创建线程池，后台执行打印 JStack
Executors.newSingleThreadExecutor().execute(new Runnable() {
@Override
public void run() {
// 获得路径
String dumpPath = url.getParameter(Constants.DUMP_DIRECTORY, System.getProperty("user.home"));
SimpleDateFormat sdf;
// 获得系统
String OS = System.getProperty("os.name").toLowerCase();
// window system don't support ":" in file name
if(OS.contains("win")){
sdf = new SimpleDateFormat("yyyy-MM-dd_HH-mm-ss");
}else {
sdf = new SimpleDateFormat("yyyy-MM-dd_HH:mm:ss");
}
String dateStr = sdf.format(new Date());
// 获得输出流
FileOutputStream jstackStream = null;
try {
jstackStream = new FileOutputStream(new File(dumpPath, "Dubbo_JStack.log" + "." + dateStr));
// 打印 JStack
JVMUtil.jstack(jstackStream);
} catch (Throwable t) {
logger.error("dump jstack error", t);
} finally {
// 释放信号量
guard.release();
// 释放输出流
if (jstackStream != null) {
try {
jstackStream.flush();
jstackStream.close();
} catch (IOException e) {
}
}
}
// 记录最后打印时间
lastPrintTime = System.currentTimeMillis();
}
});
}
}
然后才是分析1月3号的日志，发现BLOCKED信息，有大量线程都在等待 DubboServerHandler-10.10.1.1:20881-thread-819 这个线程
Line 129: "taskExecutor-128" Id=1408 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 498: "taskExecutor-97" Id=1375 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 625: "taskExecutor-88" Id=1366 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 752: "taskExecutor-79" Id=1357 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 945: "DubboServerHandler-10.10.1.1:20881-thread-1200" Id=1341 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 984: "DubboServerHandler-10.10.1.1:20881-thread-1199" Id=1340 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1023: "DubboServerHandler-10.10.1.1:20881-thread-1198" Id=1339 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1062: "DubboServerHandler-10.10.1.1:20881-thread-1197" Id=1338 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1101: "DubboServerHandler-10.10.1.1:20881-thread-1196" Id=1337 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1140: "DubboServerHandler-10.10.1.1:20881-thread-1195" Id=1336 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1179: "DubboServerHandler-10.10.1.1:20881-thread-1194" Id=1335 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1218: "DubboServerHandler-10.10.1.1:20881-thread-1193" Id=1334 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1257: "DubboServerHandler-10.10.1.1:20881-thread-1192" Id=1333 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1296: "DubboServerHandler-10.10.1.1:20881-thread-1191" Id=1332 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1335: "DubboServerHandler-10.10.1.1:20881-thread-1190" Id=1331 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1374: "DubboServerHandler-10.10.1.1:20881-thread-1189" Id=1330 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1413: "DubboServerHandler-10.10.1.1:20881-thread-1188" Id=1329 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1452: "DubboServerHandler-10.10.1.1:20881-thread-1187" Id=1328 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1491: "DubboServerHandler-10.10.1.1:20881-thread-1186" Id=1327 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1530: "DubboServerHandler-10.10.1.1:20881-thread-1185" Id=1326 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1569: "DubboServerHandler-10.10.1.1:20881-thread-1184" Id=1325 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1608: "DubboServerHandler-10.10.1.1:20881-thread-1183" Id=1324 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1647: "DubboServerHandler-10.10.1.1:20881-thread-1182" Id=1323 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1686: "DubboServerHandler-10.10.1.1:20881-thread-1181" Id=1322 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1725: "DubboServerHandler-10.10.1.1:20881-thread-1180" Id=1321 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1764: "DubboServerHandler-10.10.1.1:20881-thread-1179" Id=1320 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1803: "DubboServerHandler-10.10.1.1:20881-thread-1178" Id=1319 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1842: "DubboServerHandler-10.10.1.1:20881-thread-1177" Id=1318 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1881: "DubboServerHandler-10.10.1.1:20881-thread-1176" Id=1317 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1920: "DubboServerHandler-10.10.1.1:20881-thread-1175" Id=1316 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1959: "DubboServerHandler-10.10.1.1:20881-thread-1174" Id=1315 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 1998: "DubboServerHandler-10.10.1.1:20881-thread-1173" Id=1314 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2037: "DubboServerHandler-10.10.1.1:20881-thread-1172" Id=1313 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2076: "DubboServerHandler-10.10.1.1:20881-thread-1171" Id=1312 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2115: "DubboServerHandler-10.10.1.1:20881-thread-1170" Id=1311 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2154: "DubboServerHandler-10.10.1.1:20881-thread-1169" Id=1310 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2248: "DubboServerHandler-10.10.1.1:20881-thread-1168" Id=1304 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2287: "DubboServerHandler-10.10.1.1:20881-thread-1167" Id=1303 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2326: "DubboServerHandler-10.10.1.1:20881-thread-1166" Id=1302 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2365: "DubboServerHandler-10.10.1.1:20881-thread-1165" Id=1301 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2404: "DubboServerHandler-10.10.1.1:20881-thread-1164" Id=1300 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2443: "DubboServerHandler-10.10.1.1:20881-thread-1163" Id=1299 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2482: "DubboServerHandler-10.10.1.1:20881-thread-1162" Id=1298 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2521: "DubboServerHandler-10.10.1.1:20881-thread-1161" Id=1297 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2560: "DubboServerHandler-10.10.1.1:20881-thread-1160" Id=1296 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2599: "DubboServerHandler-10.10.1.1:20881-thread-1159" Id=1295 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2638: "DubboServerHandler-10.10.1.1:20881-thread-1158" Id=1294 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2677: "DubboServerHandler-10.10.1.1:20881-thread-1157" Id=1293 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2716: "DubboServerHandler-10.10.1.1:20881-thread-1156" Id=1292 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2755: "DubboServerHandler-10.10.1.1:20881-thread-1155" Id=1291 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2794: "DubboServerHandler-10.10.1.1:20881-thread-1154" Id=1290 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2833: "DubboServerHandler-10.10.1.1:20881-thread-1153" Id=1289 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2872: "DubboServerHandler-10.10.1.1:20881-thread-1152" Id=1288 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2911: "DubboServerHandler-10.10.1.1:20881-thread-1151" Id=1287 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2950: "DubboServerHandler-10.10.1.1:20881-thread-1150" Id=1286 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 2989: "DubboServerHandler-10.10.1.1:20881-thread-1149" Id=1285 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3028: "DubboServerHandler-10.10.1.1:20881-thread-1148" Id=1284 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3067: "DubboServerHandler-10.10.1.1:20881-thread-1147" Id=1282 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3106: "DubboServerHandler-10.10.1.1:20881-thread-1146" Id=1281 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3145: "DubboServerHandler-10.10.1.1:20881-thread-1145" Id=1280 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3184: "DubboServerHandler-10.10.1.1:20881-thread-1144" Id=1279 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3223: "DubboServerHandler-10.10.1.1:20881-thread-1143" Id=1278 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3262: "DubboServerHandler-10.10.1.1:20881-thread-1142" Id=1277 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3301: "DubboServerHandler-10.10.1.1:20881-thread-1141" Id=1276 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3340: "DubboServerHandler-10.10.1.1:20881-thread-1140" Id=1275 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3379: "DubboServerHandler-10.10.1.1:20881-thread-1139" Id=1274 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3418: "DubboServerHandler-10.10.1.1:20881-thread-1138" Id=1273 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3457: "DubboServerHandler-10.10.1.1:20881-thread-1137" Id=1272 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3496: "DubboServerHandler-10.10.1.1:20881-thread-1136" Id=1271 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3535: "DubboServerHandler-10.10.1.1:20881-thread-1135" Id=1270 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3574: "DubboServerHandler-10.10.1.1:20881-thread-1134" Id=1269 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3613: "DubboServerHandler-10.10.1.1:20881-thread-1133" Id=1268 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3652: "DubboServerHandler-10.10.1.1:20881-thread-1132" Id=1267 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3691: "DubboServerHandler-10.10.1.1:20881-thread-1131" Id=1266 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3730: "DubboServerHandler-10.10.1.1:20881-thread-1130" Id=1265 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3769: "DubboServerHandler-10.10.1.1:20881-thread-1129" Id=1264 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3808: "DubboServerHandler-10.10.1.1:20881-thread-1128" Id=1263 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3847: "DubboServerHandler-10.10.1.1:20881-thread-1127" Id=1262 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3886: "DubboServerHandler-10.10.1.1:20881-thread-1126" Id=1261 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3925: "DubboServerHandler-10.10.1.1:20881-thread-1125" Id=1260 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 3964: "DubboServerHandler-10.10.1.1:20881-thread-1124" Id=1259 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4003: "DubboServerHandler-10.10.1.1:20881-thread-1123" Id=1258 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4042: "DubboServerHandler-10.10.1.1:20881-thread-1122" Id=1257 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4120: "DubboServerHandler-10.10.1.1:20881-thread-1120" Id=1255 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4159: "DubboServerHandler-10.10.1.1:20881-thread-1119" Id=1254 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4198: "DubboServerHandler-10.10.1.1:20881-thread-1118" Id=1253 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4237: "DubboServerHandler-10.10.1.1:20881-thread-1117" Id=1252 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4276: "DubboServerHandler-10.10.1.1:20881-thread-1116" Id=1251 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4315: "DubboServerHandler-10.10.1.1:20881-thread-1115" Id=1250 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4354: "DubboServerHandler-10.10.1.1:20881-thread-1114" Id=1249 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4393: "DubboServerHandler-10.10.1.1:20881-thread-1113" Id=1248 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4432: "DubboServerHandler-10.10.1.1:20881-thread-1112" Id=1247 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4471: "DubboServerHandler-10.10.1.1:20881-thread-1111" Id=1246 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4510: "DubboServerHandler-10.10.1.1:20881-thread-1110" Id=1245 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4549: "DubboServerHandler-10.10.1.1:20881-thread-1109" Id=1244 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4588: "DubboServerHandler-10.10.1.1:20881-thread-1108" Id=1243 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4627: "DubboServerHandler-10.10.1.1:20881-thread-1107" Id=1242 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4666: "DubboServerHandler-10.10.1.1:20881-thread-1106" Id=1241 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4705: "DubboServerHandler-10.10.1.1:20881-thread-1105" Id=1240 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4744: "DubboServerHandler-10.10.1.1:20881-thread-1104" Id=1239 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4783: "DubboServerHandler-10.10.1.1:20881-thread-1103" Id=1238 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4822: "DubboServerHandler-10.10.1.1:20881-thread-1102" Id=1237 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4916: "DubboServerHandler-10.10.1.1:20881-thread-1101" Id=1231 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4955: "DubboServerHandler-10.10.1.1:20881-thread-1100" Id=1230 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 4994: "DubboServerHandler-10.10.1.1:20881-thread-1099" Id=1229 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5033: "DubboServerHandler-10.10.1.1:20881-thread-1098" Id=1228 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5072: "DubboServerHandler-10.10.1.1:20881-thread-1097" Id=1227 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5111: "DubboServerHandler-10.10.1.1:20881-thread-1096" Id=1226 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5150: "DubboServerHandler-10.10.1.1:20881-thread-1095" Id=1225 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5189: "DubboServerHandler-10.10.1.1:20881-thread-1094" Id=1224 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5228: "DubboServerHandler-10.10.1.1:20881-thread-1093" Id=1223 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5267: "DubboServerHandler-10.10.1.1:20881-thread-1092" Id=1222 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5306: "DubboServerHandler-10.10.1.1:20881-thread-1091" Id=1221 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5345: "DubboServerHandler-10.10.1.1:20881-thread-1090" Id=1220 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5384: "DubboServerHandler-10.10.1.1:20881-thread-1089" Id=1219 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5423: "DubboServerHandler-10.10.1.1:20881-thread-1088" Id=1218 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5462: "DubboServerHandler-10.10.1.1:20881-thread-1087" Id=1217 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5501: "DubboServerHandler-10.10.1.1:20881-thread-1086" Id=1216 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5540: "DubboServerHandler-10.10.1.1:20881-thread-1085" Id=1215 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5579: "DubboServerHandler-10.10.1.1:20881-thread-1084" Id=1214 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5618: "DubboServerHandler-10.10.1.1:20881-thread-1083" Id=1213 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5657: "DubboServerHandler-10.10.1.1:20881-thread-1082" Id=1212 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5696: "DubboServerHandler-10.10.1.1:20881-thread-1081" Id=1211 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5735: "DubboServerHandler-10.10.1.1:20881-thread-1080" Id=1210 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5774: "DubboServerHandler-10.10.1.1:20881-thread-1079" Id=1209 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5813: "DubboServerHandler-10.10.1.1:20881-thread-1078" Id=1208 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5852: "DubboServerHandler-10.10.1.1:20881-thread-1077" Id=1207 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5891: "DubboServerHandler-10.10.1.1:20881-thread-1076" Id=1206 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5930: "DubboServerHandler-10.10.1.1:20881-thread-1075" Id=1205 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 5969: "DubboServerHandler-10.10.1.1:20881-thread-1074" Id=1204 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6008: "DubboServerHandler-10.10.1.1:20881-thread-1073" Id=1203 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6047: "DubboServerHandler-10.10.1.1:20881-thread-1072" Id=1202 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6086: "DubboServerHandler-10.10.1.1:20881-thread-1071" Id=1201 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6125: "DubboServerHandler-10.10.1.1:20881-thread-1070" Id=1200 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6164: "DubboServerHandler-10.10.1.1:20881-thread-1069" Id=1199 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6203: "DubboServerHandler-10.10.1.1:20881-thread-1068" Id=1198 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6242: "DubboServerHandler-10.10.1.1:20881-thread-1067" Id=1197 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6281: "DubboServerHandler-10.10.1.1:20881-thread-1066" Id=1196 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6320: "DubboServerHandler-10.10.1.1:20881-thread-1065" Id=1195 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6359: "DubboServerHandler-10.10.1.1:20881-thread-1064" Id=1194 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6398: "DubboServerHandler-10.10.1.1:20881-thread-1063" Id=1193 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6437: "DubboServerHandler-10.10.1.1:20881-thread-1062" Id=1192 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6476: "DubboServerHandler-10.10.1.1:20881-thread-1061" Id=1191 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6515: "DubboServerHandler-10.10.1.1:20881-thread-1060" Id=1190 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6554: "DubboServerHandler-10.10.1.1:20881-thread-1059" Id=1189 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6593: "DubboServerHandler-10.10.1.1:20881-thread-1058" Id=1188 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6632: "DubboServerHandler-10.10.1.1:20881-thread-1057" Id=1187 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6671: "DubboServerHandler-10.10.1.1:20881-thread-1056" Id=1186 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6710: "DubboServerHandler-10.10.1.1:20881-thread-1055" Id=1185 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6749: "DubboServerHandler-10.10.1.1:20881-thread-1054" Id=1184 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6788: "DubboServerHandler-10.10.1.1:20881-thread-1053" Id=1183 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6827: "DubboServerHandler-10.10.1.1:20881-thread-1052" Id=1182 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6866: "DubboServerHandler-10.10.1.1:20881-thread-1051" Id=1181 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6944: "DubboServerHandler-10.10.1.1:20881-thread-1049" Id=1179 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 6983: "DubboServerHandler-10.10.1.1:20881-thread-1048" Id=1178 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7022: "DubboServerHandler-10.10.1.1:20881-thread-1047" Id=1177 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7061: "DubboServerHandler-10.10.1.1:20881-thread-1046" Id=1176 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7100: "DubboServerHandler-10.10.1.1:20881-thread-1045" Id=1175 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7139: "DubboServerHandler-10.10.1.1:20881-thread-1044" Id=1174 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7178: "DubboServerHandler-10.10.1.1:20881-thread-1043" Id=1173 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7217: "DubboServerHandler-10.10.1.1:20881-thread-1042" Id=1172 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7256: "DubboServerHandler-10.10.1.1:20881-thread-1041" Id=1171 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7295: "DubboServerHandler-10.10.1.1:20881-thread-1040" Id=1170 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7334: "DubboServerHandler-10.10.1.1:20881-thread-1039" Id=1169 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7373: "DubboServerHandler-10.10.1.1:20881-thread-1038" Id=1168 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7412: "DubboServerHandler-10.10.1.1:20881-thread-1037" Id=1167 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7451: "DubboServerHandler-10.10.1.1:20881-thread-1036" Id=1166 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7490: "DubboServerHandler-10.10.1.1:20881-thread-1035" Id=1165 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7529: "DubboServerHandler-10.10.1.1:20881-thread-1034" Id=1164 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7568: "DubboServerHandler-10.10.1.1:20881-thread-1033" Id=1163 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7607: "DubboServerHandler-10.10.1.1:20881-thread-1032" Id=1162 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7646: "DubboServerHandler-10.10.1.1:20881-thread-1031" Id=1161 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7685: "DubboServerHandler-10.10.1.1:20881-thread-1030" Id=1160 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7724: "DubboServerHandler-10.10.1.1:20881-thread-1029" Id=1159 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7763: "DubboServerHandler-10.10.1.1:20881-thread-1028" Id=1158 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7802: "DubboServerHandler-10.10.1.1:20881-thread-1027" Id=1157 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7841: "DubboServerHandler-10.10.1.1:20881-thread-1026" Id=1156 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7880: "DubboServerHandler-10.10.1.1:20881-thread-1025" Id=1155 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7919: "DubboServerHandler-10.10.1.1:20881-thread-1024" Id=1154 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7958: "DubboServerHandler-10.10.1.1:20881-thread-1023" Id=1153 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 7997: "DubboServerHandler-10.10.1.1:20881-thread-1022" Id=1152 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8036: "DubboServerHandler-10.10.1.1:20881-thread-1021" Id=1151 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8075: "DubboServerHandler-10.10.1.1:20881-thread-1020" Id=1150 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8114: "DubboServerHandler-10.10.1.1:20881-thread-1019" Id=1149 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8153: "DubboServerHandler-10.10.1.1:20881-thread-1018" Id=1148 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8192: "DubboServerHandler-10.10.1.1:20881-thread-1017" Id=1147 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8231: "DubboServerHandler-10.10.1.1:20881-thread-1016" Id=1146 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8270: "DubboServerHandler-10.10.1.1:20881-thread-1015" Id=1145 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8309: "DubboServerHandler-10.10.1.1:20881-thread-1014" Id=1144 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8348: "DubboServerHandler-10.10.1.1:20881-thread-1013" Id=1143 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8387: "DubboServerHandler-10.10.1.1:20881-thread-1012" Id=1142 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8426: "DubboServerHandler-10.10.1.1:20881-thread-1011" Id=1141 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8465: "DubboServerHandler-10.10.1.1:20881-thread-1010" Id=1140 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8504: "DubboServerHandler-10.10.1.1:20881-thread-1009" Id=1139 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8543: "DubboServerHandler-10.10.1.1:20881-thread-1008" Id=1138 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8582: "DubboServerHandler-10.10.1.1:20881-thread-1007" Id=1137 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8621: "DubboServerHandler-10.10.1.1:20881-thread-1006" Id=1136 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8660: "DubboServerHandler-10.10.1.1:20881-thread-1005" Id=1135 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8699: "DubboServerHandler-10.10.1.1:20881-thread-1004" Id=1134 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8738: "DubboServerHandler-10.10.1.1:20881-thread-1003" Id=1133 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8816: "DubboServerHandler-10.10.1.1:20881-thread-1001" Id=1131 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8855: "DubboServerHandler-10.10.1.1:20881-thread-1000" Id=1130 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 Line 8894: "DubboServerHandler-10.10.1.1:20881-thread-999" Id=1129 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943
具体错误信息
"taskExecutor-128" Id=1408 BLOCKED on ch.qos.logback.core.util.CachingDateFormatter@69af014b owned by "DubboServerHandler-10.10.1.1:20881-thread-819" Id=943 at ch.qos.logback.core.util.CachingDateFormatter.format(CachingDateFormatter.java:45) - blocked on ch.qos.logback.core.util.CachingDateFormatter@69af014b at ch.qos.logback.classic.pattern.DateConverter.convert(DateConverter.java:61) at ch.qos.logback.classic.pattern.DateConverter.convert(DateConverter.java:23) at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36) at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:115) at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:141) at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:39) at ch.qos.logback.core.encoder.LayoutWrappingEncoder.encode(LayoutWrappingEncoder.java:115) at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:230) at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235) at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383) at ch.qos.logback.classic.Logger.debug(Logger.java:494) at sun.reflect.GeneratedMethodAccessor213.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:627) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:609) at org.springframework.aop.aspectj.AspectJMethodBeforeAdvice.before(AspectJMethodBeforeAdvice.java:43) at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:55) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.aspectj.AspectJAfterAdvice.invoke(AspectJAfterAdvice.java:47) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:672) ... Number of locked synchronizers = 1 - java.util.concurrent.ThreadPoolExecutor$Worker@4c0ee2a5
查了下 CachingDateFormatter logback的版本是1.2.3 代码实现如下，是用的synchorinzed 对象锁，问题暂时定位到这里
//
// Source code recreated from a .class file by IntelliJ IDEA
// (powered by FernFlower decompiler)
//
package ch.qos.logback.core.util;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.TimeZone;
public class CachingDateFormatter {
long lastTimestamp = -1L;
String cachedStr = null;
final SimpleDateFormat sdf;
public CachingDateFormatter(String pattern) {
this.sdf = new SimpleDateFormat(pattern);
}
public final String format(long now) {
synchronized(this) {
if (now != this.lastTimestamp) {
this.lastTimestamp = now;
this.cachedStr = this.sdf.format(new Date(now));
}
return this.cachedStr;
}
}
public void setTimeZone(TimeZone tz) {
this.sdf.setTimeZone(tz);
}
}
查了下logback 1.2.3 是有这个问题，1.3.0.-alpha10已经解决
1.3.0-alpha10 中实现方式如下
//
// Source code recreated from a .class file by IntelliJ IDEA
// (powered by FernFlower decompiler)
//
package ch.qos.logback.core.util;
import java.time.Instant;
import java.time.OffsetDateTime;
import java.time.ZoneId;
import java.time.format.DateTimeFormatter;
import java.util.concurrent.atomic.AtomicReference;
public class CachingDateFormatter {
final DateTimeFormatter dtf;
final ZoneId zoneId;
final AtomicReference<CachingDateFormatter.CacheTuple> atomicReference;
public CachingDateFormatter(String pattern) {
this(pattern, (ZoneId)null);
}
public CachingDateFormatter(String pattern, ZoneId aZoneId) {
this.dtf = DateTimeFormatter.ofPattern(pattern);
if (aZoneId == null) {
this.zoneId = ZoneId.systemDefault();
} else {
this.zoneId = aZoneId;
}
this.dtf.withZone(this.zoneId);
CachingDateFormatter.CacheTuple cacheTuple = new CachingDateFormatter.CacheTuple(-1L, (String)null);
this.atomicReference = new AtomicReference(cacheTuple);
}
public final String format(long now) {
CachingDateFormatter.CacheTuple localCacheTuple = (CachingDateFormatter.CacheTuple)this.atomicReference.get();
CachingDateFormatter.CacheTuple oldCacheTuple = localCacheTuple;
if (now != localCacheTuple.lastTimestamp) {
Instant instant = Instant.ofEpochMilli(now);
OffsetDateTime currentTime = OffsetDateTime.ofInstant(instant, this.zoneId);
String result = this.dtf.format(currentTime);
localCacheTuple = new CachingDateFormatter.CacheTuple(now, result);
this.atomicReference.compareAndSet(oldCacheTuple, localCacheTuple);
}
return localCacheTuple.cachedStr;
}
static class CacheTuple {
final long lastTimestamp;
final String cachedStr;
public CacheTuple(long lastTimestamp, String cachedStr) {
this.lastTimestamp = lastTimestamp;
this.cachedStr = cachedStr;
}
}
}
最后反思：
1） pinpoint 确实能发现不少问题，这个pinpoint全链路的跟踪还是不错的
2）缺乏对dubbo线程池的深入理解
3）对生产问题要有敬畏心，深入下去才能发现问题
4）还有一个优化建议，dubbo的dispatcher策略more是 all 所有消息都派发到线程池，包括请求、响应、连接事件、断开事件、心跳等。，建议改成message
message 只有请求响应消息派发到线程池，其他连接断开事件、心跳等消息，直接在IO线程上执行。
下面是具体各个类型的分别
all
所有消息都派发到线程池，包括请求、响应、连接事件、断开事件、心跳等。
direct
所有消息都不派发到线程池，全部在IO线程上直接执行。
message
只有请求响应消息派发到线程池，其他连接断开事件、心跳等消息，直接在IO线程上执行。
execution
只请求消息派发到线程池，不含响应，响应和其他连接断开事件、心跳等消息，直接在IO线程上执行。
connection
在IO线程上，将连接断开事件放入队列，有序逐个执行，其他消息派发到线程池。