如何记录龙卷风套接字接受时间？

Question

当我阅读tornado源代码时，我希望记录每个socket接受时间，所以我在accept_handler上添加一个日志，如下所示：

def accept_handler(fd, events):
    for i in xrange(_DEFAULT_BACKLOG):
        if removed[0]:
            # The socket was probably closed
            return
        try:
            connection, address = sock.accept()
        except socket.error as e:
            # _ERRNO_WOULDBLOCK indicate we have accepted every
            # connection that is available.
            if errno_from_exception(e) in _ERRNO_WOULDBLOCK:
                return
            # ECONNABORTED indicates that there was a connection
            # but it was closed while still in the accept queue.
            # (observed on FreeBSD).
            if errno_from_exception(e) == errno.ECONNABORTED:
                continue
            raise
        set_close_exec(connection.fileno())
        gen_log.warning('accept at {}'.format(io_loop.time()))
        callback(connection, address)

我的处理程序是一个阻塞函数，它阻塞IOLOOP3S并返回'Hello World'。

[W 170916 22:06:01 netutil:278] accept at 1505624761.04
sleep at 1505624761.04
wake at 1505624764.04
[I 170916 22:06:04 web:2063] 200 GET / (192.168.10.243) 3005.47ms
[W 170916 22:06:04 netutil:278] accept at 1505624764.04
sleep at 1505624764.04
wake at 1505624767.05
[I 170916 22:06:07 web:2063] 200 GET / (192.168.10.243) 3005.02ms
[W 170916 22:06:07 netutil:278] accept at 1505624767.05
sleep at 1505624767.05
wake at 1505624770.05
[I 170916 22:11:06 web:2063] 200 GET / (192.168.10.243) 3003.87ms
[W 170916 22:11:06 netutil:278] accept at 1505625066.86
sleep at 1505625066.86
wake at 1505625069.86
[I 170916 22:11:09 web:2063] 200 GET / (192.168.10.243) 3002.22ms
[W 170916 22:11:09 netutil:278] accept at 1505625069.86
sleep at 1505625069.86
wake at 1505625072.87
[I 170916 22:11:12 web:2063] 200 GET / (192.168.10.243) 3004.91ms
[W 170916 22:11:12 netutil:278] accept at 1505625072.87
sleep at 1505625072.87
wake at 1505625075.87
[I 170916 22:11:15 web:2063] 200 GET / (192.168.10.243) 3004.71ms
[W 170916 22:11:15 netutil:278] accept at 1505625075.87
sleep at 1505625075.87
wake at 1505625078.88
[I 170916 22:11:18 web:2063] 200 GET / (192.168.10.243) 3006.12ms
[W 170916 22:11:18 netutil:278] accept at 1505625078.88
sleep at 1505625078.88
wake at 1505625081.89
[I 170916 22:11:21 web:2063] 200 GET / (192.168.10.243) 3006.07ms
[W 170916 22:11:21 netutil:278] accept at 1505625081.89
sleep at 1505625081.89
wake at 1505625084.89
[I 170916 22:11:24 web:2063] 200 GET / (192.168.10.243) 3005.07ms
[W 170916 22:11:24 netutil:278] accept at 1505625084.9
sleep at 1505625084.9
wake at 1505625087.9
[I 170916 22:11:27 web:2063] 200 GET / (192.168.10.243) 3006.34ms

Answer 1

在龙卷风中，阻塞处理程序阻塞一切。在本例中，这包括对accept()的下一次调用（accept循环末尾对callback()的调用最终将到达处理程序）。要在Tornado中实现任何并发，您必须使所有处理程序都是非阻塞的（在IOLoop线程上。您可以使用ThreadPoolExecutor将工作转移到其他线程，在这些线程中，您可以任意阻塞，但不能调用其他Tornado方法）。