如何正确测试setTimeout调用？排查测试用例超时问题

你在验证restartService里的setTimeout是否正确触发队列消息发送时，遇到了测试用例超时的问题，哪怕加了超时时间也没用，咱们来拆解一下问题根源和修复方案。

业务函数代码 #

function restartService(startTime) { 
  const endTime = (new Date()).getTime(); 
  const fiveMinLeft = 5 * 60 * 1000 - (endTime - startTime); 
  console.log(startTime, endTime, fiveMinLeft); 
  setTimeout(() => { 
    console.log('clock'); 
    Producer.create({ queueUrl: process.env.MY_QUEUE }).send([{ stuff: true }], (err) => { 
      console.log('err', err); 
    }); 
  }, fiveMinLeft); 
  return Promise.resolve(); 
}

测试用例代码 #

it.only('send a message after 5 minutes to the queue', (done) => { 
  const msg = 'msg' 
  const sendStub = sinon.spy(); 
  const clock = sinon.useFakeTimers(); 
  sinon.stub(global.db.Deposit, 'findAll').returns(Promise.resolve([{ id: 2 }])); 
  sinon.stub(global.db.Transaction, 'findOrCreate').returns(Promise.resolve()); 
  sinon.stub(Producer, 'create').returns({ send: sendStub }); 

  WatcherService.handleMessage(msg, () => { 
    global.db.Transaction.findOrCreate.restore(); 
    global.db.Deposit.findAll.restore(); 
    Producer.create.should.be.called(); 
    done(); 
  }); 

  clock.tick(5 * 1000 * 60); 
});

问题根源分析 #

咱们揪出几个核心问题：

1. Fake Timers的时序完全搞反了
   你先调用了WatcherService.handleMessage，之后才触发clock.tick快进时间。但restartService里的startTime和endTime是基于真实时间计算的（因为fake timers是在这之后才接管时间的），这会导致fiveMinLeft的计算值和你预期的5分钟完全不符——甚至可能是负数！就算之后调用clock.tick，也触发不了原本预期的setTimeout回调，自然done()永远不会被调用，测试就超时了。

2. 断言和done()的时机错误
   你把断言和done()放在了handleMessage的回调里，这个回调只是handleMessage执行完成的回调，而非setTimeout触发后的回调。换句话说，你在setTimeout还没执行的时候就结束了测试，完全没等到目标逻辑运行。

3. 异步逻辑的处理遗漏
   如果WatcherService.handleMessage是异步操作，你没等待它完成就调用clock.tick，会导致时序混乱，setTimeout可能还没被注册到fake timers里就快进时间了。

修复后的测试用例 #

调整时序，确保fake timers先接管时间，再执行业务逻辑，最后在正确时机断言和结束测试：

it.only('send a message after 5 minutes to the queue', async (done) => { 
  const msg = 'msg' 
  const sendStub = sinon.spy(); 
  // 先启动fake timers，让所有时间相关API都用模拟时间
  const clock = sinon.useFakeTimers(); 

  // 预先stub好所有依赖
  const depositStub = sinon.stub(global.db.Deposit, 'findAll').returns(Promise.resolve([{ id: 2 }]));
  const transactionStub = sinon.stub(global.db.Transaction, 'findOrCreate').returns(Promise.resolve());
  const producerStub = sinon.stub(Producer, 'create').returns({ send: sendStub }); 

  try {
    // 等待handleMessage执行完成（如果是回调式，要改成等待回调触发）
    await WatcherService.handleMessage(msg);

    // 此时restartService已经执行，setTimeout已注册到fake timers
    clock.tick(5 * 60 * 1000); // 快进5分钟，触发setTimeout回调

    // 现在才做断言，验证目标逻辑是否执行
    producerStub.should.be.called();
    sendStub.should.be.called(); // 可以额外断言send方法是否被调用

    done();
  } catch (err) {
    done(err); // 捕获错误，避免测试静默失败
  } finally {
    // 不管测试成功失败，都恢复stubs和fake timers
    depositStub.restore();
    transactionStub.restore();
    producerStub.restore();
    clock.restore();
  }
});

额外优化建议 #

• 如果restartService的startTime是外部传入的，测试时直接用fake timers的模拟时间，比如clock.now，这样fiveMinLeft会精确等于5分钟，避免计算偏差：

  const testStartTime = clock.now;
  restartService(testStartTime);
  

• 确认WatcherService.handleMessage内部确实正确调用了restartService，这个链路断了的话，后续逻辑都不会执行。
• 如果handleMessage是回调式而非返回Promise，要把clock.tick和断言放在回调内部，再调用done()，但仍要保证fake timers先启动。

内容的提问来源于stack exchange，提问作者Shamoon