Python Tornado WebSocket连接关闭后仍保持打开状态

Question

Python Tornado WebSocket连接关闭后仍保持打开状态

6

我有一个Tornado Websocket服务器，希望在30分钟内无活动后自动超时。我使用self.close（）来关闭经过30分钟不活动的连接。但是似乎有些连接即使被关闭后仍然保持打开状态。

以下是代码的核心部分（在得到这里的帮助后实现：如何在Tornado Websocket中在一定时间后自动关闭连接 serverside）：

打开连接：

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

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

另一个例子是当假定没有更多开放的连接时，连接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，因为self.close()会调用on_close，但on_close()并不会被self.close()调用。

- patapouf_ai

你不需要调用common_close()方法，close()方法会自动调用它。注意：如果你可以检查打开的连接列表，即使在第二次关闭66919时，也只有3个连接！ - Ja8zyjits

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

是的，完全正确。在30分钟之前，close方法已经被调用了66919次，然后它超时了并尝试再次关闭（这意味着它实际上没有被关闭）。这就是我不理解的地方... - patapouf_ai

2个回答

1

看起来这两个重复的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秒钟内向服务器发送消息，可能会导致问题。

这只是我的猜测。

- NeoWang

不，正如您所看到的，它们被称为30分钟间隔。 - patapouf_ai

如果我不显式地放置common_close()，force_close就不会调用它...我不知道为什么。 - patapouf_ai

但是如果它被关闭了，那么实例就不应该再存在了，对吧？它怎么还能有一个计时器呢？此外，从日志中我可以看出，在第一次“关闭”时没有调用 on_message，因为当发送消息时，我会在输出中打印它 (print "Client %s sent message : %s" % (self.id, message))，但我没有看到这个。 - patapouf_ai

谢谢，虽然很有帮助，但它让我思考了。 - patapouf_ai

网页内容由stack overflow 提供, 点击上面的

可以查看英文原文，
原文链接

- Ben Darnell · Accepted Answer

common_close被调用两次，但连接只超时一次。在第一个示例中，66919在21:51被关闭，因为客户端通过on_close干净地关闭了连接，然后在22:21由于超时再次关闭。即使关闭连接，连接对象仍然存在。连接不是打开的，只有超时保持激活。如果它处于活动状态，则需要从on_close(或common_close)中删除超时。

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

自Tornado 4.1开始，on_close()将被self.close()调用。