Python Tornado Websocket连接在关闭后仍然打开

Posted 2023-02-16

【中文标题】Python Tornado Websocket连接在关闭后仍然打开

【英文标题】：Python Tornado Websocket Connections still open after being closed

【发布时间】：2015-07-15 08:08:50

【问题描述】：

我有一个 Tornado Websocket 服务器，我想在闲置 30 分钟后超时。我使用self.close() 在闲置 30 分钟后关闭连接。但似乎某些连接即使在关闭后仍保持打开状态。

这里是代码的基本部分（在获得帮助后实现：How to automatically close connection serverside after a certain time in Tornado Websocket）：

打开连接：

class WebSocketHandler(tornado.websocket.WebSocketHandler):
    def open(self, *args):
        self.id = self.generate_id()
        self.stream.set_nodelay(True)
        # ... DO STUFF ...
        self.ini_time = datetime.now()
        self.message_number = 0
        self.last_message_time = self.ini_time
        self.write_message("Connection SUCCESSFUL! Thanks for connecting! Your connection ID is: %d :)" % self.id)
        self.timeout = tornado.ioloop.IOLoop.current().add_timeout(timedelta(minutes=30), self.force_close)
        print datetime.now()
        print "New connection. ID: %d" % self.id
        print "Total number of open connections: %d" % len(clients)

收到消息时：

    def on_message(self, message):        
        """
        when we receive some message we want some message handler..
        for this example i will just print message to console
        """
        if self.timeout:
            tornado.ioloop.IOLoop.current().remove_timeout(self.timeout)
        self.timeout = tornado.ioloop.IOLoop.current().add_timeout(timedelta(minutes=30), self.force_close)
        self.last_message_time = datetime.now()
        self.message_number+=1

        print datetime.now()
        print "Client %s sent message : %s" % (self.id, message)
        # ... DO STUFF ...

关闭时：

def on_close(self):
    self.common_close()

def common_close(self):
    print datetime.now()
    print "Open connections are:"
    print clients.keys()
    print "Closing connection %d." % self.id 

    end = datetime.now()
    timeonline = end - self.ini_time
    timeconlastmsg = self.last_message_time - self.ini_time
    print "Total time online:"
    print timeonline
    print "Time between connection start and last message received:"
    print timeconlastmsg
    if self.id in clients.keys():
        del clients[self.id]
    print "Number of open connections: %d" % len(clients)
    print "Open connections are:"
    print clients.keys()

按时超时：

def force_close(self):
    timout =  datetime.now()
    print timout
    print "Connection %d timed out, server is dropping the connection." % self.id
    self.common_close()
    self.close() 

超时有效，函数force_close 被调用。但似乎即使在被调用并从clients 删除连接之后，该连接仍然是打开的并且处于活动状态。

这是程序的示例输出：

New connection. ID: 66919
Total number of open connections: 3
2015-07-14 21:51:48.387892
New connection. ID: 12012
Total number of open connections: 4
2015-07-14 21:51:48.641603
Open connections are:
[66919, 12012, 11281, 97458]
Closing connection 66919.
Total time online:
0:00:00.404316
Time between connection start and last message received:
0:00:00
Number of open connections: 3
Open connections are:
[12012, 11281, 97458]
... ...
Number of open connections: 4
Open connections are:
[66246, 12012, 97458, 6069]
2015-07-14 22:21:47.906129
Connection 97458 timed out, server is dropping the connection.
2015-07-14 22:21:47.906167
Open connections are:
[66246, 12012, 97458, 6069]
Closing connection 97458.
Total time online:
0:30:00.000450
Time between connection start and last message received:
0:00:00
Number of open connections: 3
Open connections are:
[66246, 12012, 6069]
2015-07-14 22:21:48.237407
Connection 66919 timed out, server is dropping the connection.
2015-07-14 22:21:48.237444
Open connections are:
[66246, 12012, 6069]
Closing connection 66919.
Total time online:
0:30:00.000143
Time between connection start and last message received:
0:00:00
Number of open connections: 3

可以看出，66919 以 30 分钟的间隔“关闭”了两次。有什么想法吗？

另一个连接 3358 的示例在假定没有更多打开的连接时被关闭（再次关闭两次，间隔为 30 分钟）：

Open connections are:
[7046, 16287]
2015-07-15 11:01:13.604125
New connection. ID: 3358
Total number of open connections: 3
2015-07-15 11:01:28.429574
Open connections are:
[7046, 3358, 16287]
Closing connection 3358.
Total time online:
0:00:14.825568
Time between connection start and last message received:
0:00:00
Number of open connections: 2
Open connections are:
[7046, 16287]
--
Open connections are:
[]
2015-07-15 11:31:13.629530
Connection 3358 timed out, server is dropping the connection.
2015-07-15 11:31:13.629586
Open connections are:
[]
Closing connection 3358.
Total time online:
0:30:00.025556
Time between connection start and last message received:
0:00:00
Number of open connections: 0
Open connections are:
[]

有人指出我不应该在force_close 中调用common_close，因为on_close 会被self.close() 调用，但on_close() 不会被self.close() 调用。

【问题讨论】：

你不需要调用common_close()，close()方法会自动调用common_close()注意如果你可以检查打开的连接列表甚至只有3个连接当 66919 第二次关闭时！！！

我也是这么想的。但是不行，close()方法没有调用common_close()，不知道为什么。

没错，在 30 分钟前已经在 66919 上调用了 close，然后它超时并再次尝试关闭（这意味着它并没有真正关闭）。这就是我不明白的......

【参考方案1】：

common_close 被调用两次，但连接只超时一次。在您的第一个示例中，66919 在 21:51 关闭，因为客户端干净地关闭了连接（通过on_close），然后由于超时而在 22:21 再次关闭。连接对象即使在关闭后仍继续存在。连接未打开；只有超时仍然有效。如果on_close（或common_close）处于活动状态，您需要移除超时。

您还应该在open() 中启动第一个超时，而不是等待on_message()，并且force_close() 应该将self.timeout 设置为无。

由于 Tornado 4.1 on_close() 将被 self.close() 调用。

【讨论】：

谢谢！事实上，在open() 上开始超时是有意义的。但我不明白当连接实例不再存在时，超时如何仍然保持活动状态......

连接和超时无关。如果你想在连接关闭时停止超时，你必须这么说。并且 self.close() 应该调用 on_close()，至少从 Tornado 4.1 开始：github.com/tornadoweb/tornado/commit/…

好的，但是当self 不再存在时，如何调用self.force_close() ...

self 只要有引用就一直存在，就像关闭的文件对象一样：f = open(filename); f.close(); f.read() 会抛出异常，因为它已关闭，但 f 仍然存在。跨度>

谢谢本！您能否将其添加到您的答案中，我会给您赏金。

【参考方案2】：

看起来这两个重复的 id 恰好相隔 30 分钟。这只能意味着一件事，当连接被关闭时，会安排另一个计时器，第二个计时器在超时时打印重复的日志。从你的代码来看，这只能发生在on_message。

您的客户端如何处理连接关闭？客户端是否有可能在收到 FIN 时立即向服务器发送消息？

在tornado源码中，

# Give the client a few seconds to complete a clean shutdown,
# otherwise just close the connection.
self._waiting = self.stream.io_loop.add_timeout(
      self.stream.io_loop.time() + 5, self._abort)

所以服务器给客户端5秒的时间来终止连接，如果客户端在这5秒内向服务器发送消息，可能会导致问题。

这只是我的猜测。

【讨论】：

不，你可以看到它们被称为 30min appart。

如果我不明确地把 common_close() 也不会被 force_close 调用......我不知道为什么。

但如果它被关闭，实例不应该再存在了不是吗？怎么还有定时器？同样从日志中我可以看出，在第一次“关闭”期间没有调用on_message，因为当发送消息时，我将其打印在输出中（print "Client %s sent message : %s" % (self.id, message)），但我没有看到。

谢谢，这很有帮助。这让我思考。