1.前言
我一直以为，一个IT技术人员，重要的不是知道多少语言，新语法或者新框架，而是遇到问题分析问题的能力。而分析问题的能力，一方面需要多锻炼，另一方面也要多看一些好的分析过程。以前工作过程查过不少比较深的bug，比如踩内存，coredump这类的问题，但是都觉得反正自己知道就行了懒得去写文章，现在觉得有点可惜，因为久了就容易忘，而且一些好的想法不能分享给更多的人也很可惜，况且有更多的人看到可能还会给你指出纰漏。
刚好在这里，再提一个我认为学习技术的方法问题。比如学一个新的框架，文档先浏览一下，然后就是照着教程的例子运行，接着弄懂例子的运行原理（看源码）。抓住在使用框架过程中遇到的问题，并以那个问题为切入点深入分析，这样一方面能解决问题；另一方面能借机对框架有更深入的了解，因为框架内容那么多，也不可能面面俱到，但是至少遇到问题的地方你深挖是有价值的。
2.问题描述
使用tornado并发测试一个http服务，而刚好服务有异常，未能响应。
因此，运行后一段时间，接收到了超时异常：
Traceback (most recent call last): File "test_asynchttpclient.py", line 72, inIOLoop.current().run_sync(run) File "/usr/local/lib/python2.7/dist-packages/tornado/ioloop.py", line 458, in run_sync return future_cell[0].result() File "/usr/local/lib/python2.7/dist-packages/tornado/concurrent.py", line 238, in result raise_exc_info(self._exc_info) File "/usr/local/lib/python2.7/dist-packages/tornado/gen.py", line 1063, in run yielded = self.gen.throw(*exc_info) File "test_asynchttpclient.py", line 67, in run yield [aync_post(payload) for payload in payload_ls] File "/usr/local/lib/python2.7/dist-packages/tornado/gen.py", line 1055, in run value = future.result() File "/usr/local/lib/python2.7/dist-packages/tornado/concurrent.py", line 238, in result raise_exc_info(self._exc_info) File "/usr/local/lib/python2.7/dist-packages/tornado/gen.py", line 828, in callback result_list.append(f.result()) File "/usr/local/lib/python2.7/dist-packages/tornado/concurrent.py", line 238, in result raise_exc_info(self._exc_info) File "/usr/local/lib/python2.7/dist-packages/tornado/gen.py", line 1063, in run yielded = self.gen.throw(*exc_info) File "test_asynchttpclient.py", line 58, in aync_post body=payload File "/usr/local/lib/python2.7/dist-packages/tornado/gen.py", line 1055, in run value = future.result() File "/usr/local/lib/python2.7/dist-packages/tornado/concurrent.py", line 238, in result raise_exc_info(self._exc_info) File "", line 3, in raise_exc_info
tornado.httpclient.HTTPError: HTTP 599: Timeout during request
这个问题让我疑惑的地方是，我没有设置超时，为什么会抛出超时异常？是否有默认的超时设置，设置在哪里？
3.问题分析
因为我是并发测试了100条请求，所以异常信息就很乱，所以首先，我要做的就是简化得到的信息，我把请求改为1条，这时异常信息就很清晰了。
接着，在tornado的源码中，搜索异常的提示“HTTP 599: Timeout during request”，但是搜索不到。
还是从异常提示信息入手，在异常的函数堆栈中，提示错在：run_sync这个函数，因此进入源码查看函数定义：
def run_sync(self, func, timeout=None):
"""
The keyword-only argument ``timeout`` may be used to set a maximum duration for the function. If the timeout expires,a `TimeoutError` is raised.
"""
我猜测可能跟这个timeout参数有关，可能会有默认的值，一开始我们还是尽量不要深入源码，所以我就尝试传一个timeout值为10进去（因为之前发现是大概15秒以上才抛异常）。运行后，结果是这样：
Traceback (most recent call last): File "test_asynchttpclient.py", line 72, inIOLoop.current().run_sync(run,10)
File "/usr/local/lib/python2.7/dist-packages/tornado/ioloop.py", line 457, in run_sync
raise TimeoutError('Operation timed out after %s seconds' % timeout)
tornado.ioloop.TimeoutError: Operation timed out after 10 seconds
这时，我们发现，异常不一样！于是我试着尝试了20秒和30秒，发现20秒和30秒都是提示之前的异常。所以我想看看超时的秒数是多少，加入了打印时间。
begin 2017-07-31 10:34:25.092218
end 2017-07-31 10:34:45.111876
begin 2017-07-31 10:36:19.603607
end 2017-07-31 10:36:39.627447
相同的时间！好像每次超时都是20秒，查问题最重要的就是关注这些规律性的东西。因此我又实验了几次，最终的结论就是：超时就是20秒！
然后我就用20和2000（代码一般都是毫秒）去搜索源码，也没有什么发现。
没头绪的时候，就又回去看异常提示信息，异常信息和函数堆栈是查问题最重要的信息。
tornado.httpclient.HTTPError: HTTP 599: Timeout during request
我们看到“httpclient.HTTPError”，httpclient应该是tornado的一个文件,于是我们搜索这个文件，找到了并且找到了HTTPError这个类：
classHTTPError(Exception):
"""Exception thrown for an unsuccessful HTTP request.
Attributes:
* ``code`` - HTTP error integer error code, e.g. 404. Error code 599 is
used when no HTTP response was received, e.g. for a timeout.
* ``response`` - `HTTPResponse` object, if any.
Note that if ``follow_redirects`` is False, redirects become HTTPErrors,
and you can look at ``error.response.headers['Location']`` to see the
destination of the redirect.
"""
哈哈，里面提到了599错误，这不就是异常信息里面提到的599错误吗！因此，我们以关键字“HTTPError”搜索，查找传递599作为参数的调用的地方，最后发现只有两个地方是有可能：
分别是SimpleAsyncHTTPClient::_on_timeout 和 _HTTPConnection::_on_timeout。
而分析SimpleAsyncHTTPClient::_on_timeout后发现，根据python的语法规定，类方法如果是以下划线开头，表示为protect方法，因此该方法基本上就是内部使用了，然后看了下其他地方的调用，发现有一个地方（SimpleAsyncHTTPClient::fetch_impl）用到了：
functools.partial(self._on_timeout, key,"in request queue"))
因此不可能输出异常信息打印的那句话，所以结果就只能是_HTTPConnection::_on_timeout。我们还需要来验证一下：
_HTTPConnection::_on_connect
上图的代码逻辑就是：如果_HTTPConnection::request有request_timeout值，就给设置一个超时异常，所以接下来我们要看是这个request_timeout是什么。
查看AsyncHTTPClient::fetch的源码以及根据之前文章对AsyncHTTPClient的分析，我们知道在AsyncHTTPClient::fetch的时候，会构造request对象：
request=HTTPRequest(url=request,**kwargs)
self.defaults=dict(HTTPRequest._DEFAULTS)
request=_RequestProxy(request,self.defaults)
而这个request对象就刚好赋值给_HTTPConnection::request，因此我们去看HTTPRequest类：
而_RequestProxy对象，则是把HTTPRequest类的_DEFAULTS赋值给成员：
哈哈，终于找到了，结合上面得出的20秒超时，我们可以确定，这个超时就是在这个位置设置的。
4.结论
AsyncHTTPClient::fetch会通过HTTPRequest类构造请求对象，并且使用HTTPRequest的一些默认的限制值，里面包括了：
connect_timeout=20.0,
request_timeout=20.0,
follow_redirects=True,
max_redirects=5,
。。。。。。
因此，即使我们调用run_sync没有设置timeout，都是AsyncHTTPClient::fetch构造的一些工具对象还是有默认的超时参数。
