意外的 tornado.ioloop.PeriodicCallback 行为

Question

我想弄明白PeriodicCallback是怎么被安排的，于是我写了这个脚本：

import time
import tornado.ioloop

t0 = time.time()

def foo():
    time.sleep(1)
    print(time.time() - t0)

tornado.ioloop.PeriodicCallback(foo, 2000).start()
tornado.ioloop.IOLoop.instance().start()

我原本以为它会每2秒或每3秒触发一次，这取决于tornado是否等到上一个事件完成后再安排下一个事件。但是，我得到了这个结果：

3.00190114975
6.00296115875
10.0029530525
14.0029621124
18.0029540062
22.0050959587
26.0040180683
30.005161047
34.0053040981

这是怎么回事呢？

Answer 1

在Tornado应用中，即使是在“后台”的PeriodicCallback里，使用睡眠（sleep）也是个坏主意，因为这会阻塞IOLoop，导致它无法正确安排其他任务。如果你在使用Tornado，就需要把所有耗时的阻塞调用换成非阻塞的方式（或者把它们放到其他线程去处理）。比如，把睡眠操作换成IOLoop.add_timeout，把网络操作换成IOStream或者其他异步库等等。

Answer 2

我觉得你看到的延迟是因为运行IOLoop时的额外开销造成的。例如，如果我把PeriodicCallback的运行间隔改成每5秒一次，我得到的输出就是：

6.00595116615
12.0075321198
17.0060141087
22.0051832199
27.0067241192
32.0061450005
37.0066981316
42.0063281059
47.0067460537

这基本上就是你预期的结果。另外，关于你最初的问题，PeriodicCallback会在执行完休眠后安排下次回调的运行时间（这直接来自Tornado的源代码）：

class PeriodicCallback(object):
    def __init__(self, callback, callback_time, io_loop=None):
        self.callback = callback
        if callback_time <= 0:
            raise ValueError("Periodic callback must have a positive callback_time")
        self.callback_time = callback_time
        self.io_loop = io_loop or IOLoop.current()
        self._running = False
        self._timeout = None

    def start(self):
        """Starts the timer."""
        self._running = True
        self._next_timeout = self.io_loop.time()
        self._schedule_next()

    def _run(self):
        if not self._running:
            return
        try:
            self.callback() # Your function runs here.
        except Exception:
            app_log.error("Error in periodic callback", exc_info=True)
        self._schedule_next()  # Schedule next run after calling self.callback

    def _schedule_next(self):
        if self._running:
            current_time = self.io_loop.time()
            while self._next_timeout <= current_time:
                self._next_timeout += self.callback_time / 1000.0
            self._timeout = self.io_loop.add_timeout(self._next_timeout, self._run) # The callback is actually scheduled with the ioloop here.