fix(wle): 超时参数真正生效 —— 售后拦截 20s 不重试、表级探测走 querySlow

11-13 09:10 那轮钉钉推送 300s 超时没发出去。除了业务库本身变慢,代码里还有两笔白等:

1. `{ timeoutMs: 240000 }` 是无效参数
   cloudDatabase 只读 connectRequestTimeoutMs / requestTimeout。mssql 12.x 上请求级
   request.timeout 不生效,超时只能靠池配置级 requestTimeout,而共享池(query())的
   池级超时在 pool 创建时就定死 —— 所以「给足 4 分钟」从来没生效过,实际一路按
   60s(普通 query)/ 300s(querySlow)掐断。
   → cloudDatabase 两个查询入口加 warnLegacyTimeoutOption():再传 timeoutMs 就告警,
     不再静默当没看见。

2. 售后拦截子查询:名义 240s → 真 20s,且不重试
   两张售后表在 rpt 副本里是堆表,实测 4.5s / 8.5s。原来超时后 query() 还把它当
   可重试错误 resetPool + 重查一次,白等 60s(11-13 日志里约 2 分钟)。
   改成 querySlow + connectRequestTimeoutMs=20000 + maxAttempts=1:超了就按既有
   catch 降级「不剔除」,不为一个补充判据把整批核验拖进超时窗口。

3. 空窗口的表级 MAX(query_time) 探测改走 querySlow(180s,maxAttempts=1)
   全表 MAX 实测已跑不进 60s,用共享池等于永远探测不到 → sourceLastUpdate 恒空,
   「0 单是没发货还是没同步」又分不清了。探测失败只需退回「不知道」,不值得重试。

顺带修一个时间炸弹测试:用例「窗口 0 行但数据源是新的」硬编码 sourceMaxQueryTime
为 2026-11-02 09:58,而服务层算 ageMinutes 用的是真实时钟(registry.beijingNow)——
隔一天就变成「停更 24h」,该用例在 origin/main 上从 11-03 起一直是红的。
改成相对当前时间。

测试:warehouseLogisticsException 36/36 通过(新增 2 条「超时参数必须真生效」断言)。
This commit is contained in:
yanhui 2026-11-14 09:28:27 +08:00
parent f8b99151b5
commit 3062182417
3 changed files with 91 additions and 9 deletions

View File

@ -76,6 +76,24 @@ function isTransientError(error) {
);
}
/**
* ⚠️ `options.timeoutMs` 是个「看着能用、其实没人读」的参数 —— 历史踩坑,留个告警别再犯。
*
* 根因:mssql 12.x 上请求级 `request.timeout` 不生效,超时只能靠**池配置级** requestTimeout,
* 而共享池(query())的池级超时在 pool 创建时就定死了,调用方改不了。想放宽只有两条路:
* · querySlow(sql, params, { connectRequestTimeoutMs }) —— 临时独立连接,可任意放宽;
* · query(sql, params, { requestTimeout }) —— 只对独立连接路径(queryWithFreshConnection)有意义。
* 2026-11-14 实况:WLE 服务层两处 `{ timeoutMs: 240000 }` 想着「给足 4 分钟」,
* 实际一路按 60s/300s 跑,11-13 那轮钉钉推送就因此超时没推出去。
*/
function warnLegacyTimeoutOption(options, caller) {
if (!options || options.timeoutMs === undefined) return;
console.warn(
`[CloudDB] ${caller} 收到无效参数 timeoutMs=${options.timeoutMs}(已被忽略,不会放宽超时);`
+ '需要更长超时请改用 querySlow + connectRequestTimeoutMs'
);
}
function isTruthy(value) {
return value === true || value === 1 || String(value || '').toLowerCase() === 'true' || String(value || '') === '1';
}
@ -1036,6 +1054,7 @@ const resetPool = async () => {
* @param {object} params - 命名参数对象
*/
const query = async (sqlText, params = {}, options = {}) => {
warnLegacyTimeoutOption(options, 'query()');
const maxAttempts = parsePositiveInt(options.maxAttempts, 2);
for (let attempt = 1; attempt <= maxAttempts; attempt += 1) {
@ -1072,6 +1091,7 @@ const query = async (sqlText, params = {}, options = {}) => {
};
const queryWithFreshConnection = async (sqlText, params = {}, options = {}) => {
warnLegacyTimeoutOption(options, 'queryWithFreshConnection()');
const maxAttempts = parsePositiveInt(options.maxAttempts, 2);
for (let attempt = 1; attempt <= maxAttempts; attempt += 1) {

View File

@ -152,6 +152,14 @@ async function loadShippedPackages(batch) {
return rows || [];
}
// 🔥 2026-11-14 修:原来调这里写的是 `{ timeoutMs: 240000 }` —— **这个参数没人读**。
// mssql 12.x 上请求级 request.timeout 不生效,超时只能靠池配置级 requestTimeout,
// 而共享池(query())的池级超时在 pool 创建时就定死了,改不了。结果是「想给 4 分钟」
// 实际一路按默认 60s 掐断(11-14 实测全表 MAX 已经跑不进 60s → 探测永远返回空)。
// 真正生效的写法只有 querySlow(临时独立连接)+ connectRequestTimeoutMs。
const SOURCE_LAST_UPDATE_TIMEOUT_MS = Number(process.env.CANGKU_WLE_SOURCE_LAST_UPDATE_TIMEOUT_MS)
|| 180000;
/**
* 整张镜像表最后被灌库的时刻(表级新鲜度)。
*
@ -163,16 +171,18 @@ async function loadShippedPackages(batch) {
*
* 成本:全表 `MAX(query_time)` 在一个 402 万行的视图上实测 **13.5s**(谓词下推差),
* 所以**只在窗口 0 行时才调**(正常批次一行都不用付这笔钱),结果随主结果进 5 分钟缓存。
* ⚠️ 11-14 实测已退化到 60s 以上,所以超时上限 180s + maxAttempts=1
* (超时就退回「不知道」,重试只会把等待翻倍 —— 原来 query() 默认 2 次 × 60s 白等)。
*
* @returns {Promise<string>} 'YYYY-MM-DD HH:mm:ss',取不到返回空串
*/
async function loadSourceLastUpdate() {
try {
const rows = await cloudDatabase.query(
const rows = await cloudDatabase.querySlow(
`SELECT MAX(e.query_time) AS max_q
FROM dbo.jst_order_express_details e WITH (NOLOCK)`,
{},
{ timeoutMs: 240000 }
{ connectRequestTimeoutMs: SOURCE_LAST_UPDATE_TIMEOUT_MS, maxAttempts: 1 }
);
return formatDateTime(rows?.[0]?.max_q);
} catch (err) {
@ -188,8 +198,15 @@ async function loadSourceLastUpdate() {
// · 只查「本来就会报异常」的 oId(正常单不查,量级从 9800 降到几十);
// · 两套店铺表**并发**查,总耗时取较慢的那条(~8.5s),而不是相加的 13s;
// · 结果进 5 分钟结果缓存,页面自动刷新时基本命中缓存。
//
// 🔥 2026-11-14 修:超时从「名义 240s」改成「真 20s,且不重试」。
// 原来写 `{ timeoutMs: 240000 }`(无效参数),实际按共享池 60s 掐;
// 超时后 query() 还把它当可重试错误 —— resetPool + 再查一次,**再多等 60s**。
// 11-13 09:10 那轮推送就是这么被拖掉 2 分钟的(日志:售后拦截 60s 超时 → 重连重试)。
// 售后表跟不上时业务影响只是「少剔几单」,不值得为它把整批核验拖进超时窗口:
// 2 倍实测余量(8.5s → 20s)够用,超了就降级不剔(catch 里已有兜底)。
const INTERCEPT_QUERY_BATCH = 500;
const INTERCEPT_QUERY_TIMEOUT_MS = 240000;
const INTERCEPT_QUERY_TIMEOUT_MS = 20000;
/**
* 找出「现场拦截、货已被售后仓签收」的订单(业务 2026-10-23 口径)。
@ -219,7 +236,7 @@ async function loadInterceptedOrders(rows) {
const oIds = ids.slice(i, i + INTERCEPT_QUERY_BATCH).join(',');
for (const source of registry.INTERCEPT_AFTERSALE_SOURCES) {
tasks.push((async () => {
const hits = await cloudDatabase.query(
const hits = await cloudDatabase.querySlow(
`SELECT h.o_id
FROM ${source.header} h WITH (NOLOCK)
JOIN ${source.item} it WITH (NOLOCK) ON it.as_id = ${source.headerAsId}
@ -228,7 +245,8 @@ async function loadInterceptedOrders(rows) {
GROUP BY h.o_id
HAVING SUM(ISNULL(it.r_qty, 0)) > 0`,
{},
{ timeoutMs: INTERCEPT_QUERY_TIMEOUT_MS }
// maxAttempts: 1 —— 超时就在 catch 里降级「不剔除」,别让重连重试再白等一轮
{ connectRequestTimeoutMs: INTERCEPT_QUERY_TIMEOUT_MS, maxAttempts: 1 }
);
return hits || [];
})().catch((err) => {

View File

@ -145,11 +145,13 @@ test('状态为空时按运单号区分:有号=未揽收,无号=无物流单
const dbPath = require.resolve('../src/config/cloudDatabase');
function stubDb(rows, options = {}) {
const calls = { times: 0, sql: [], params: [] };
const handler = async (sql, params) => {
const calls = { times: 0, sql: [], params: [], options: [], api: [] };
const makeHandler = (api) => async (sql, params, opts) => {
calls.times += 1;
calls.sql.push(String(sql));
calls.params.push(params || {});
calls.options.push(opts || {});
calls.api.push(api);
// 售后拦截判定会额外查两张售后表 —— 按表名分流,别把物流行当成售后行
if (/jst_returnAndRefundInfo|jst_qmcust_refundlist/u.test(String(sql))) {
return options.interceptRows || [];
@ -164,7 +166,7 @@ function stubDb(rows, options = {}) {
id: dbPath,
filename: dbPath,
loaded: true,
exports: { query: handler, querySlow: handler },
exports: { query: makeHandler('query'), querySlow: makeHandler('querySlow') },
};
return calls;
}
@ -698,13 +700,21 @@ test('窗口 0 行 + 数据源停更 → emptyWindow/sourceStale,hint 明说
test('窗口 0 行但数据源是新的 → 仍然提示「0 条记录」,不能静默全绿', async () => {
const nov2 = new Date(2026, 10, 2, 10, 0, 0);
// ⚠️ sourceLastUpdate 必须是「相对真实现在」的时间,不能像原来那样硬编码 2026-11-02 09:58。
// 服务层算 ageMinutes 用的是 registry.beijingNow()(真实时钟),不是测试传进来的 now ——
// 硬编码的日期过一天就变成「停更 24h」,这个用例第二天起就必挂(2026-11-14 实测挂在 main 上)。
const freshText = new Intl.DateTimeFormat('sv-SE', {
timeZone: 'Asia/Shanghai',
year: 'numeric', month: '2-digit', day: '2-digit',
hour: '2-digit', minute: '2-digit', second: '2-digit', hour12: false,
}).format(new Date(Date.now() - 3 * 60 * 1000));
await withStub(async (svc) => {
const data = await svc.getLogisticsExceptions({ date: '2026-11-02', now: nov2, limit: 100 });
assert.equal(data.freshness.emptyWindow, true);
assert.equal(data.freshness.sourceStale, false, '表是新的,不该报停更');
assert.match(data.freshness.hint, /0 条发货记录/, '真 0 单也要说清是「库里没有记录」');
assert.match(data.freshness.hint, /数据源本身正常/);
}, [], { sourceMaxQueryTime: '2026-11-02 09:58:00' });
}, [], { sourceMaxQueryTime: freshText });
});
test('窗口有行时不做全表探测(省掉 13.5s 的表级 MAX)', async () => {
@ -715,3 +725,37 @@ test('窗口有行时不做全表探测(省掉 13.5s 的表级 MAX)', async
assert.equal(calls.sql.filter((s) => /MAX\(\s*e\.query_time\s*\)/iu.test(s)).length, 0);
});
});
// ── ⑨ 超时参数必须「真生效」(2026-11-14)──────────────────────────────────
// 起因:11-13 09:10 那轮钉钉推送 300s 超时没推出去。查代码发现两处写了
// `{ timeoutMs: 240000 }` 想「给足 4 分钟」,而 cloudDatabase **根本不读 timeoutMs**
// (mssql 12.x 请求级 request.timeout 不生效,只能靠池配置级 requestTimeout,
// 共享池的池级超时创建时就定死了)—— 实际一路按 60s 掐断,
// 超时后 query() 还当可重试错误重连再查一次,日志里白等了约 2 分钟。
test('售后拦截查询走 querySlow + 20s 短超时 + 不重试', async () => {
await withStub(async (svc, calls) => {
await svc.getLogisticsExceptions({ date: '2026-10-21', now: at(21, 10, 0), limit: 100 });
const idx = calls.sql.findIndex((s) => /jst_returnAndRefundInfo|jst_qmcust_refundlist/u.test(s));
assert.ok(idx >= 0, '这批有异常单,应该去查售后表');
assert.equal(calls.api[idx], 'querySlow', '必须走 querySlow:query() 的池级超时调用方改不了');
assert.equal(calls.options[idx].connectRequestTimeoutMs, 20000, '2 倍实测余量(8.5s → 20s)就够');
assert.equal(calls.options[idx].maxAttempts, 1, '超时就降级「不剔除」,别重连重试白等一轮');
assert.equal(calls.options[idx].timeoutMs, undefined, 'timeoutMs 是无效参数,不许再写');
}, rows, { interceptRows: [{ o_id: 1 }] });
});
test('空窗口的表级 MAX 探测也走 querySlow(共享池 60s 跑不动全表)', async () => {
const nov2 = new Date(2026, 10, 2, 10, 0, 0);
await withStub(async (svc, calls) => {
await svc.getLogisticsExceptions({ date: '2026-11-02', now: nov2, limit: 100 });
const idx = calls.sql.findIndex((s) => /MAX\(\s*e\.query_time\s*\)/iu.test(s));
assert.ok(idx >= 0, '空窗口要探测表级最后灌库时刻');
assert.equal(calls.api[idx], 'querySlow');
assert.ok(
Number(calls.options[idx].connectRequestTimeoutMs) >= 120000,
`全表 MAX 实测已超 60s,必须放宽,实际 ${calls.options[idx].connectRequestTimeoutMs}`
);
assert.equal(calls.options[idx].maxAttempts, 1, '探测失败退回「不知道」即可,不值得重试');
assert.equal(calls.options[idx].timeoutMs, undefined);
}, [], { sourceMaxQueryTime: '2026-11-01 07:55:04' });
});