Python脚本中requests.Timeout异常未触发问题排查

问题背景 #

• 环境：Mac系统，Python 3.10.15
• 代码实现：

def send_prediction_request2(self, request_id: str, timeout) -> dict:
    url = self.baseUrl + self.analysis_endpoint
    logger.info(f'About to call {url} for request id {request_id}')

    try:
        duration = Chronometer()
        headers = {"content-type": "application/json", "Authorization": "Bearer " + self.token}
        r = requests.post(url, data=self.payload, headers=headers, timeout=timeout)
        logger.info(f'Response received from {url} for request id {request_id} with status code {r.status_code} '
                    f'with timeout of {timeout} and response time is {duration.time_spent()}')
        r.raise_for_status()
        return r.json()

    except requests.exceptions.Timeout as e:
        logger.error(f'call to {url} timedout after {timeout} seconds with the exception of {str(e)}')
        raise
    except requests.RequestException as e:
        logger.error(f'call to {url}  failed: {str(e)}')
        raise

• 异常现象：
  1. 传入timeout=(2,2)（连接超时2秒、读取超时2秒）时，存在连接耗时超过2秒的请求未触发超时异常；
  2. 传入int类型timeout=20时，部分请求耗时超20秒也未抛出异常。

核心原因分析及排查方向 #

1. 对requests timeout参数的理解偏差 #

requests的timeout参数规则容易被误解：

• 单值int（如20）：同时将连接超时和读取超时设置为该值，并非整个请求的总耗时上限。
• 元组(connect, read)：
  • connect：仅统计TCP握手阶段的超时时间，DNS解析、TCP连接前的预处理时间不计入。如果DNS解析耗时超过2秒，即使TCP握手只用1秒，总耗时3秒也不会触发连接超时。
  • read：指连接建立后，服务器连续两次发送数据的最大间隔时间，而非整个响应的总耗时。如果服务器断断续续发送数据，每次间隔都不超过read值（比如每1秒发一次），即使总耗时超过read（比如5秒），也不会触发读取超时。

2. 自定义计时工具的准确性问题 #

代码中使用Chronometer()统计耗时，需确认：

• 计时是否从requests.post调用前就启动？如果Chronometer创建后立即计时，而拼接URL、准备headers等前置操作耗时较长，会导致日志中的duration.time_spent()包含非请求阶段的时间，误以为请求超时但实际未超。
• 可替换为Python标准库的time.perf_counter()验证计时准确性：

  import time
  start = time.perf_counter()
  r = requests.post(url, data=self.payload, headers=headers, timeout=timeout)
  elapsed = time.perf_counter() - start
  logger.info(f'实际请求耗时：{elapsed}秒')
  

3. 重定向或代理的影响 #

如果请求存在重定向（requests默认自动跟随），每个重定向的子请求都会单独应用timeout设置。比如一次请求跳转到3个地址，每个子请求的连接+读取都在超时范围内，但总耗时会超过单个子请求的超时值，此时不会触发异常。可在日志中打印重定向历史排查：

logger.info(f'请求重定向历史：{[resp.url for resp in r.history]}')

4. 异常处理的覆盖范围 #

代码中捕获requests.exceptions.Timeout是正确的，它包含ConnectTimeout（连接超时）和ReadTimeout（读取超时）两个子类，能覆盖所有requests抛出的超时场景，这部分代码无问题。

验证建议 #

1. 单独测试DNS解析耗时：在请求前手动解析域名，统计耗时：

   import socket
   start = time.perf_counter()
   socket.gethostbyname_ex(url.split('://')[1].split('/')[0])
   logger.info(f'DNS解析耗时：{time.perf_counter() - start}秒')
   

2. 模拟超时场景：搭建测试服务器，在建立连接后延迟3秒再返回数据，设置timeout=(2,2)验证是否触发ReadTimeout；或连接无法快速响应的地址，验证ConnectTimeout是否触发。
3. 检查服务器响应模式：若服务器流式返回数据，确认每次数据间隔是否小于设置的read超时值。

内容的提问来源于stack exchange，提问作者reza