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線程上，將連接斷開事件放入隊列，有序逐個執行，其他消息派發到線程池。