tornado之TCPServer性能测试

在下面这个博客里,介绍了tornado的异步TCPServer和TCPClient。

http://yunjianfei.iteye.com/blog/2186646

那么,tornado的性能到底怎么样呢?让我们来做一个性能测试吧。

 

这里推荐关于C10K问题的一个文章:http://www.kegel.com/c10k.html

 

准备工作

在开始性能测试前,需要修改一些相关的系统参数。

 

一.修改MAX open files

 

首先运行下面命令,查看单个进程运行时,能够打开的最多文件描述符(即FD)

ulimit -n

本人的运行结果为: 65535

 

这个数值有点小,如果一个进程打开10万个文件或者FD,就会出现以下错误:

error: too many open files

那么,我们开始修改。

打开 /etc/security/limits.conf 并添加(如果已经存在,则修改数值)

* soft nofile 1000000
* hard nofile 1000000

修改完毕后,重新开一个shell窗口,或者重新登录shell就会使设置生效。

再次运行ulimit -n  可以看到已经是1000000

 

二.解决TCP的TIME_WAIT问题

如果在短时间内,TCPServer收到大量的连接(比如2万以上),并且这些连接迅速关闭,就会在linux系统中,发现大量状态为TIME-WAIT的TCP连接,可以通过以下命令来查看服务器中TCP连接的状态。

netstat -n | awk ‘/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}’

 

服务器中如果出现了大量的TIME-WAIT,导致的直接后果就是,TIME-WAIT状态的TCP连接占用的资源(比如端口号)不能得到及时释放,如果端口号被耗尽,则无法建立新的连接。

 

在开始测试前,我们修改一些系统参数,来缓解TIME_WAIT问题。

执行以下几个命令:

sysctl -w net.ipv4.tcp_tw_reuse=1
sysctl -w net.ipv4.tcp_tw_recycle=1
sysctl -w net.ipv4.tcp_max_tw_buckets=5000
sysctl -w net.ipv4.tcp_syncookies=1
sysctl -w net.ipv4.ip_local_port_range=”1024 65000″

 

具体的我这里就不解释了,有兴趣的同学可以自行去查找资料。

 

测试代码

tcp_server.py

Python代码  收藏代码
  1. #!/usr/bin/env python2.7
  2. # -*- coding: utf-8 -*-
  3. from tornado import ioloop, httpclient, gen
  4. from tornado.gen import Task
  5. from tornado.tcpserver import TCPServer
  6. import pdb, time, logging
  7. from tornado import stack_context
  8. from tornado.escape import native_str
  9. #Init logging
  10. def init_logging():
  11.     logger = logging.getLogger()
  12.     logger.setLevel(logging.DEBUG)
  13.     sh = logging.StreamHandler()
  14.     formatter = logging.Formatter(‘%(asctime)s -%(module)s:%(filename)s-L%(lineno)d-%(levelname)s: %(message)s’)
  15.     sh.setFormatter(formatter)
  16.     logger.addHandler(sh)
  17.     logging.info(“Current log level is : %s”, logging.getLevelName(logger.getEffectiveLevel()))
  18. class MyServer(TCPServer):
  19.     def __init__(self, io_loop=None, **kwargs):
  20.         TCPServer.__init__(self, io_loop=io_loop, **kwargs)
  21.     def handle_stream(self, stream, address):
  22.         TCPConnection(stream, address, io_loop=self.io_loop)
  23. class TCPConnection(object):
  24.     count = 0
  25.     def __init__(self, stream, address, io_loop):
  26.         self.io_loop = io_loop
  27.         self.stream = stream
  28.         self.address = address
  29.         self.address_family = stream.socket.family
  30.         self.EOF = b’ END’
  31.         self._clear_request_state()
  32.         self._message_callback = stack_context.wrap(self._on_message)
  33.         self.stream.set_close_callback(self._on_connection_close)
  34.         self.stream.read_until(self.EOF, self._message_callback)
  35.     def _on_timeout(self):
  36.         #logging.info(“Send message..”)
  37.         self.write(“Hello client!” + self.EOF)
  38.         TCPConnection.count += 1
  39.         #logging.info(“Has treated : %s”, TCPConnection.count)
  40.         if TCPConnection.count == 0 or TCPConnection.count % 2000 == 0:
  41.             logging.info(“Has treated : %s”, TCPConnection.count)
  42.     def _on_message(self, data):
  43.         try:
  44.             timeout = 5
  45.             data = native_str(data.decode(‘latin1′))
  46.             #logging.info(“Received: %s”, data)
  47.             #self.io_loop.add_timeout(self.io_loop.time() + timeout, self._on_timeout)
  48.             self._on_timeout()
  49.         except Exception, ex:
  50.             logging.error(“Exception: %s”, str(ex))
  51.     def _clear_request_state(self):
  52.         ”"”Clears the per-request state.
  53.         ”"”
  54.         self._write_callback = None
  55.         self._close_callback = None
  56.     def set_close_callback(self, callback):
  57.         ”"”Sets a callback that will be run when the connection is closed.
  58.         ”"”
  59.         self._close_callback = stack_context.wrap(callback)
  60.     def _on_connection_close(self):
  61.         if self._close_callback is not None:
  62.             callback = self._close_callback
  63.             self._close_callback = None
  64.             callback()
  65.         self._clear_request_state()
  66.     def close(self):
  67.         self.stream.close()
  68.         # Remove this reference to self, which would otherwise cause a
  69.         self._clear_request_state()
  70.     def write(self, chunk, callback=None):
  71.         ”"”Writes a chunk of output to the stream.”"”
  72.         if not self.stream.closed():
  73.             self._write_callback = stack_context.wrap(callback)
  74.             self.stream.write(chunk, self._on_write_complete)
  75.     def _on_write_complete(self):
  76.         if self._write_callback is not None:
  77.             callback = self._write_callback
  78.             self._write_callback = None
  79.             callback()
  80. def main():
  81.     init_logging()
  82.     server = MyServer()
  83.     server.listen(8001)
  84.     ioloop.IOLoop.instance().start()
  85. if __name__ == ”__main__”:
  86.     try:
  87.         main()
  88.     except Exception, ex:
  89.         print ”Ocurred Exception: %s” % str(ex)
  90.         quit()

 

tcp_client.py

Python代码  收藏代码
  1. #!/usr/bin/env python2.7
  2. # -*- coding: utf-8 -*-
  3. from tornado import ioloop, httpclient, gen
  4. from tornado.gen import Task
  5. import pdb, time, logging
  6. import tornado.ioloop
  7. import tornado.iostream
  8. import socket
  9. from tornado import stack_context
  10. #Init logging
  11. def init_logging():
  12.     logger = logging.getLogger()
  13.     logger.setLevel(logging.DEBUG)
  14.     sh = logging.StreamHandler()
  15.     formatter = logging.Formatter(‘%(asctime)s -%(module)s:%(filename)s-L%(lineno)d-%(levelname)s: %(message)s’)
  16.     sh.setFormatter(formatter)
  17.     logger.addHandler(sh)
  18.     logging.info(“Current log level is : %s”, logging.getLevelName(logger.getEffectiveLevel()))
  19. class TCPClient(object):
  20.     test_start = False
  21.     max_connected = 20000
  22.     test_num = 20000
  23.     test_remain = test_num
  24.     test_count = 0
  25.     total_count = 0
  26.     shutdown = False
  27.     def __init__(self, host, port, io_loop=None):
  28.         self.host = host
  29.         self.port = port
  30.         self.io_loop = io_loop
  31.         self.shutdown = False
  32.         self.stream = None
  33.         self.sock_fd = None
  34.         self.EOF = b’ END’
  35.     def get_stream(self):
  36.         self.sock_fd = socket.socket(socket.AF_INET, socket.SOCK_STREAM, 0)
  37.         self.stream = tornado.iostream.IOStream(self.sock_fd)
  38.         self.stream.set_close_callback(self.on_close)
  39.     def connect(self):
  40.         self.get_stream()
  41.         self.stream.connect((self.host, self.port), self.send_message)
  42.     def on_receive(self, data):
  43.         #logging.info(“Received: %s”, data)
  44.         self.stream.close()
  45.         self.stream = None
  46.         self.sock_fd = None
  47.         TCPClient.test_count += 1
  48.         try_testing(self.io_loop)
  49.     def on_close(self):
  50.         TCPClient.total_count += 1
  51.         if TCPClient.total_count % 2000 == 0:
  52.             logging.info(“Has treat: %s”, TCPClient.total_count)
  53.         #logging.info(“—-count: %s %s  %s”, TCPClient.total_count, TCPClient.shutdown, TCPClient.test_num)
  54.         if TCPClient.shutdown and TCPClient.total_count == TCPClient.test_num:
  55.             logging.info(“shutdown”)
  56.             self.io_loop.stop()
  57.     def send_message(self):
  58.         #logging.info(“Send message….”)
  59.         self.stream.write(b”Hello Server!” + self.EOF)
  60.         self.stream.read_until(self.EOF, self.on_receive)
  61.         #logging.info(“After send….”)
  62.     def set_shutdown(self):
  63.         TCPClient.shutdown = True
  64. def _handle_exception(typ, value, tb):
  65.     logging.info(“%s  %s  %s”, typ, value, tb)
  66.     return True
  67. def try_testing(io_loop):
  68.     #logging.info(“test_count: %s, test_remain: %s”, TCPClient.test_count, TCPClient.test_remain)
  69.     if TCPClient.test_start and TCPClient.test_count >= TCPClient.max_connected and TCPClient.test_remain > 0:
  70.         TCPClient.test_start = False
  71.     if not TCPClient.test_start:
  72.         TCPClient.test_count = 0
  73.         TCPClient.test_start = True
  74.         gen = None
  75.         if TCPClient.test_remain >= TCPClient.max_connected:
  76.             gen = start_test(io_loop, TCPClient.max_connected)
  77.         elif TCPClient.test_remain > 0:
  78.             gen = start_test(io_loop, TCPClient.test_remain)
  79.         if gen:
  80.             with stack_context.ExceptionStackContext(_handle_exception):
  81.                 c = gen.next()
  82.                 while True:
  83.                     c = gen.send(c)
  84. def start_test(io_loop, count):
  85.     TCPClient.test_remain = TCPClient.test_remain - count
  86.     logging.info(“Will start %s testing! Remain: %s”, count, TCPClient.test_remain)
  87.     for i in range(count):
  88.         c = yield TCPClient(“127.0.0.1″, 8001, io_loop)
  89.         if i == (count-1) and TCPClient.test_remain <= 0:
  90.             c.set_shutdown()
  91.         c.connect()
  92. def main():
  93.     init_logging()
  94.     io_loop = tornado.ioloop.IOLoop.instance()
  95.     try_testing(io_loop)
  96.     logging.info(“**********************start ioloop******************”)
  97.     io_loop.start()
  98. if __name__ == ”__main__”:
  99.     try:
  100.         main()
  101.     except Exception, ex:
  102.         print ”Ocurred Exception: %s” % str(ex)
  103.         quit()

上面的client代码中,可以修改test_num这个数值,来改变测试case的数目,上面设置成了20000

 

测试结果

tcp_server:

2015-02-27 17:01:05,898 -server:server.py-L22-INFO: Current log level is : DEBUG
2015-02-27 17:01:30,544 -server:server.py-L55-INFO: Has treated : 2000
2015-02-27 17:01:30,807 -server:server.py-L55-INFO: Has treated : 4000
2015-02-27 17:01:31,242 -server:server.py-L55-INFO: Has treated : 6000
2015-02-27 17:01:31,510 -server:server.py-L55-INFO: Has treated : 8000
2015-02-27 17:01:31,738 -server:server.py-L55-INFO: Has treated : 10000
2015-02-27 17:01:32,220 -server:server.py-L55-INFO: Has treated : 12000
2015-02-27 17:01:32,452 -server:server.py-L55-INFO: Has treated : 14000
2015-02-27 17:01:32,743 -server:server.py-L55-INFO: Has treated : 16000
2015-02-27 17:01:33,146 -server:server.py-L55-INFO: Has treated : 18000
2015-02-27 17:01:38,342 -server:server.py-L55-INFO: Has treated : 20000

可以看到,总体来说,server的性能还是不错的,总共8s时间,处理了2万个请求+响应。

 

上面的测试结果中有个地方让我非常疑惑,最后2000个请求,中间居然耗费了5s,我在tornado的ioloop.py中加了一些debug语句跟踪后,发现是在33s的时候,卡在了ioloop的下面这一行

event_pairs = self._impl.poll(poll_timeout)

 

也就是说,epoll在等待IO事件到来,有点想不明白为什么在这里等了5s。经过多次测试,这种情况是完全可以复现的,还有待进一步调查。



发表评论

电子邮件地址不会被公开。 必填项已用 * 标注

*

您可以使用这些 HTML 标签和属性: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>

(Spamcheck Enabled)