数据库抛出“超时”异常

---

title: 数据库抛出“超时”异常分析与总结 categories:

• Blog tags:

• database

常见的四种数据库超时异常，在一周内遇到了两个。

抽空做了一下深入的分析，区分遇到的异常到底是什么。

idle-in-transaction timeout

校对库存过程中，触发的报错信息：

FATAL: terminating connection due to idle-in-transaction timeout

该报错的意思是：事务会话空闲超时，idle_in_transaction_session_timeout控制会话在事务中空闲的最长时间。如果会话在事务中的空闲时间超过指定的超时时间，PostgreSQL 将自动终止会话并回滚正在进行的事务。

通过本地复现，在arthas里发现在执行调拨入库单的库存校对时，耗时720655ms。如下图

分析数据库，一共有2116张调拨入库单，涉及70441行分录，这个数据量其实是不大的。

进一步分析发现，处理已结账调拨入库的在途计算耗时非常大：

通过这张图可以看到procSettledTFIn这个方法出现了很大的耗时，但是实际的数据库操作耗时不大。总耗时390S，可看见的耗时只有不到1S，说明Java的jdk程序在耗时。

接下来通过arthas的--skipJDKMethod false参数，将jdk的方法也打印出来，就可以非常清晰的看到问题：第3677行这个for循环占用了99.15%的耗时。

+---[99.15% 336403.559721ms ] java.util.List:forEach() #3677

for循环的源码所示，其中list表示调拨入库单的分录，instockList表示调拨出库单的分录。

// 第一层循环
list.forEach(p -> {
	p.setFields(getFieldsDefaultVal());
	// 嵌套的第二层循环
	instockList.stream()
			.filter(s -> s.getLong(InvBDConst.ID) == p.getSrcInterId()
					&& s.getLong(InvConst.ENTRY_ID) == p.getSrcEntryId()
			)
			.findFirst()
			.ifPresent(k -> {
				p.setFields(getFieldsDefaultVal());
				p.setSpId(k.getLong(InvBillConst.INSPID));
				p.setSpName(k.getString(InvConst.INSP_NAME));
				setSumTFData(inStockSign, p, k, sumData);
				procTFTransit(p, outStockSign, updateInStockValidQty, k, sumData);
			});
});

再结合数据，有70441行入库必然有70441行出库（因为入库只能由出库产生），所以这里的问题大致就可以定位到是两个超级大的嵌套for循环导致的性能开销。

优化方向，用空间换时间。下面是优化后的程序：

// 提前将List转为Map，避免在for循环嵌套
Map<String, DynamicObject> inStockMap = inStockList.stream().collect(
	Collectors.toMap(
		k -> String.format(pattern, k.getLong(InvBillConst.ID), k.getLong(InvConst.ENTRY_ID)),
		v -> v, (k1, K2) -> k1)
);
list.forEach(p -> {
	p.setFields(getFieldsDefaultVal());
	String matchKey = String.format(pattern, p.getSrcInterId(), p.getSrcEntryId());
	if (inStockMap.containsKey(matchKey)) {
		DynamicObject k = inStockMap.get(matchKey);
		p.setFields(getFieldsDefaultVal());
		p.setSpId(k.getLong(InvBillConst.INSPID));
		p.setSpName(k.getString(InvConst.INSP_NAME));
		setSumTFData(inStockSign, p, k, sumData);
		procTFTransit(p, outStockSign, updateInStockValidQty, k, sumData);
	}
});

优化后的性能表现：

+---[11.43% 495.664791ms ] java.util.List:forEach() #3684

优化对比：

	优化前	优化后	提升
耗时	336403	495ms	680%

statement_timeout

canceling statement due to statement timeout

语句超时 (statement_timeout)：statement_timeout 设置了单个查询允许执行的最长时间限制。如果查询超过了这个时间限制，PostgreSQL 将自动终止查询并返回错误信息。

执行耗时的SQL：

-- 保留前3次记录
DELETE FROM table_name 
USING table_name T1 
LEFT JOIN 
(SELECT fid from table_name_2 order by time limit 3) T2 on T1.fcid = T2.fid
WHERE T2.fid isNull or T1.fcid <> T2.fid;

至于这个SQL为什么会这么慢的原因分析：由于库存的备份表会被频繁大批量删除、大批量插入，导致产生大量内存碎片，从而导致的耗时。

临时解决办法，truncate 表以清除内存碎片；程序上的优化，使用子查询减少表之间的关联。

-- 保留前3次记录
DELETE FROM table_name 
WHERE fcid not in (SELECT fid from table_name_2 order by time limit 3);