python grpc 使用域名第一次耗时长问题

python grpc

字数统计: 2.1k阅读时长: 9 min

 2025/07/29 

最近给同事解决的 python grpc 耗时长问题…..

由来

昨天上着班突然被群里拉到一个开发任务群里，看了下聊天记录说啥慢，询问了下理清了流程：

 client    server1   model server
┌──┐        ┌──┐        ┌──┐ 
└┬─┘        └┬─┘        └─┬┘ 
 ├───http───►│            │  
 │           ├───grpc────►│  
 │           │◄──grpc─────┤  
 │◄───http───┤            │

http 客户端请求服务1，带了模型服务的 model_url，server1 会 grpc 请求 model_url，然后发现回复非常慢，把 ai-xxx 换成实际的外部 IP 就会很快。

curl --location 'http://xxxx:8870/chat' \
    --header 'Content-Type: application/json' \
    --data '{
        "stream": true,
        "messages_type": 1,
        "title": "人工智能",
        "inspiration": "文风严谨，语言简洁凝练",
        "model_config": {
            "default": true,
            "type": "xxxx",
            "model_url": "ai-xxx",
            "model_name": "xxxxx-xxxx",
            "model": "xxxxx"
        }
    }'

环境上测了下果然是，server1 的访问日志看有 9s 左右延迟，看了下环境是 k8s， ai-xxx 是直接创建的 svc 和 ep，endpoint 为外部一个模型服务的 ip 端口。看了下 server1 内的 /etc/nsswitch 正常：

1 2	$ grep hosts /etc/nsswitch.conf hosts: files dns

加了下 hosts 测下还是每次都必现，可以肯定和 k8s dns 无关了，如果是 k8s dns 5s timeout 问题，那是 IPv6 的 AAAA 记录五元组冲突导致的偶现超时，和这个不一样。

解决过程

初步怀疑是研发的 server1 后端接口逻辑有问题，但是他们说有些环境正常有些不正常，于是我让他们给个最小的 python grpc client 访问模型的 demo。这样二分排除范围，不然两个链路不好查。没想到今天测试又催这个问题看得咋样了。然后让研发把 demo 发过来看。

demo 复现

拿到 demo 有点无语，这种耗时的打印居然是用的 print，手动修改成 logging 后测试复现了，大概逻辑如下：

server_urls = [
    "ai-xxx:80",
    "10.xx.xx.xxx:10037"
]

for server_url in server_urls:
    grpc_test()

拷贝到 server1 的容器里执行，发现必现，耗时久的附近是如下 35s - 43s：

2025-07-29 16:52:35 [INFO] 🔥 开始测试GRPC连接: ai-xxx:80
2025-07-29 16:52:35 [INFO] 📡 创建Triton客户端...
2025-07-29 16:52:35 [INFO] ✅ 客户端创建成功
2025-07-29 16:52:35 [INFO] 🔍 检查服务器状态...
2025-07-29 16:52:43 [INFO]    服务器存活: ✅
2025-07-29 16:52:43 [INFO]    服务器就绪: ✅
2025-07-29 16:52:43 [INFO] ✅ 服务器状态检查通过
...
2025-07-29 16:52:44 [INFO] 🔥 开始测试GRPC连接: 10.xx.xx.xxx:10037
2025-07-29 16:52:44 [INFO] 📡 创建Triton客户端...
2025-07-29 16:52:44 [INFO] ✅ 客户端创建成功
2025-07-29 16:52:44 [INFO] 🔍 检查服务器状态...
2025-07-29 16:52:44 [INFO]    服务器存活: ✅
2025-07-29 16:52:44 [INFO]    服务器就绪: ✅
2025-07-29 16:52:44 [INFO] ✅ 服务器状态检查通过

看了下 demo 代码对应位置：

triton_client = grpcclient.InferenceServerClient(
    url=server_url,
    verbose=False
)
logging.info("✅ 客户端创建成功")

# 2. 检查服务器状态
logging.info("🔍 检查服务器状态is_server_live")
is_live = triton_client.is_server_live()
logging.info("🔍 检查服务器状态is_server_ready")
is_ready = triton_client.is_server_ready()

python -m pdb grpc-test.py 调试了下，发现这个方法只是一个纯粹的 grpc 请求：

(Pdb) n
> /usr/local/lib/python3.10/site-packages/tritonclient/grpc/_client.py(294)is_server_live()
-> try:
(Pdb) list
289  	        InferenceServerException
290  	            If unable to get liveness or has timed out.
291  	
292  	        """
293  	        metadata = self._get_metadata(headers)
294  ->	        try:
295  	            request = service_pb2.ServerLiveRequest()
296  	            if self._verbose:
297  	                print("is_server_live, metadata {}\n{}".format(metadata, request))
298  	            response = self._client_stub.ServerLive(
299  	                request=request, metadata=metadata, timeout=client_timeout

grpc 客户端用的 tritonclient:

1 2	$ pip list \| grep client tritonclient 2.57.0

pypi 查了下这个 grpc 库发现找到的仓库 triton-inference-server/client 分支和上面版本号对不上，很奇怪。

谷歌搜了下 is_server_live long time 发现能搜到同样问题 is_server_live() python GRPC client got no response，但是别人用的是 IP ，后面还把 issue 关闭了说是他们自己的网络问题。

然后让研发找 is_server_live() 的 grpc server 端研发查下 ServerLive 接口调用逻辑，另一方面让 server1 研发把 is_server_live() 注释了试试，他说走 CI 流程会稍微慢些，让我看看环境上能直接改不，于是大家一起并行操作。

稍有眉目

发现环境改了后还是复现，于是我在 demo 里改了下发现慢在第二个了：

# 2. 检查服务器状态
logging.info("🔍 检查服务器状态is_server_live")
# is_live = triton_client.is_server_live()
logging.info("🔍 检查服务器状态is_server_ready")
# is_ready = triton_client.is_server_ready()

# logging.info(f"   服务器存活: {'✅' if is_live else '❌'}")
# logging.info(f"   服务器就绪: {'✅' if is_ready else '❌'}")

# if not is_live:
#     raise Exception("服务器未存活")
# if not is_ready:
#     raise Exception("服务器未就绪")

logging.info("✅ 服务器状态检查通过")

# 3. 获取模型信息
logging.info("📋 获取模型信息...")
try:
    model_metadata = triton_client.get_model_metadata("xxxxx")

2025-07-29 17:32:32 [INFO] ✅ 客户端创建成功
2025-07-29 17:32:32 [INFO] 🔍 检查服务器状态is_server_live
2025-07-29 17:32:32 [INFO] 🔍 检查服务器状态is_server_ready
2025-07-29 17:32:32 [INFO] ✅ 服务器状态检查通过
2025-07-29 17:32:32 [INFO] 📋 获取模型信息...
2025-07-29 17:32:40 [INFO] ✅ 成功获取模型元数据
2025-07-29 17:32:40 [INFO]    模型名称: xxxx
2025-07-29 17:32:40 [INFO]    模型版本: ['1']
2025-07-29 17:32:40 [INFO] 🧠 执行简单推理测试...
2025-07-29 17:32:40 [INFO] ✅ 流启动成功
2025-07-29 17:32:40 [INFO] ✅ 推理请求发送成功
2025-07-29 17:32:40 [INFO] ⏳ 等待响应...
2025-07-29 17:32:40 [INFO] ✅ 收到成功响应
2025-07-29 17:32:40 [INFO]    输出tokens: [9]
2025-07-29 17:32:40 [INFO] 🎉 GRPC连接测试完全成功!
2025-07-29 17:32:40 [INFO] 🎉 务器 ai-xxx:80 测试成功!

这次不是前面的 is_server_live() 问题，仔细看了下代码想了下是 grpcclient 的第一个 grpc 请求有问题导致耗时长，搜索了下发现一样相似但是更耗时的问题：

https://github.com/triton-inference-server/server/issues/1821

不过上面 issue 里 triton 官方说是 grpc/grpc 的问题，搜到 Communication from c++ server to python client is too slow 说 python 很慢但是 c++ 的不慢，python 的首次 grpc 建立连接耗时很长，后续的请求都在 ms 内完成。issue 内下面大佬排查出耗时大部分开销都是在 libc 相关调用上。

众所周知，grpc 是长连接后推流，让研发要不要改代码写成连接池试试，他们说来不及。

感觉既然和 triton 无关，就搜 python grpc dns first time long 搜到了 Python client hangs on first connection 类似问题，排查和 DNS 相关，发现大佬说试试 GRPC_DNS_RESOLVER=native ，搜了下 grpc/grpc 官方文档：

* GRPC_DNS_RESOLVER
  Declares which DNS resolver to use. The default is ares if gRPC is built with
  c-ares support. Otherwise, the value of this environment variable is ignored.
  Available DNS resolver include:
  - ares (default on most platforms except iOS, Android or Node)- a DNS
    resolver based around the c-ares library
  - native - a DNS resolver based around getaddrinfo(), creates a new thread to
    perform name resolution

默认是 c 的库 c-ares 去解析的，设置为 native 则使用系统 libc 的 getaddrinfo() ，于是测试了下可以：

$ GRPC_DNS_RESOLVER=native python3  /root/test2.py 
2025-07-29 17:59:43 [INFO] ✅ tritonclient导入成功
2025-07-29 17:59:43 [INFO] ============================================================
2025-07-29 17:59:43 [INFO] 🚀 GRPC连接测试工具
2025-07-29 17:59:43 [INFO] ============================================================
2025-07-29 17:59:43 [INFO] 
📍 测试服务器: ai-xxx:80
2025-07-29 17:59:43 [INFO] ----------------------------------------
2025-07-29 17:59:43 [INFO] 🔍 测试DNS解析: ai-xxx:80
2025-07-29 17:59:43 [INFO] ✅ DNS解析成功: ai-xxx -> 10.186.44.250:80
2025-07-29 17:59:43 [INFO] 🔥 开始测试GRPC连接: ai-xxx:80
2025-07-29 17:59:43 [INFO] 📡 创建Triton客户端...
2025-07-29 17:59:43 [INFO] ✅ 客户端创建成功
2025-07-29 17:59:43 [INFO] 🔍 检查服务器状态is_server_live
2025-07-29 17:59:44 [INFO] 🔍 检查服务器状态is_server_ready
2025-07-29 17:59:44 [INFO]    服务器存活: ✅
2025-07-29 17:59:44 [INFO]    服务器就绪: ✅
2025-07-29 17:59:44 [INFO] ✅ 服务器状态检查通过
2025-07-29 17:59:44 [INFO] 📋 获取模型信息...
2025-07-29 17:59:44 [INFO] ✅ 成功获取模型元数据
2025-07-29 17:59:44 [INFO]    模型名称: xxxx
2025-07-29 17:59:44 [INFO]    模型版本: ['1']
2025-07-29 17:59:44 [INFO] 🧠 执行简单推理测试...
2025-07-29 17:59:44 [INFO] ✅ 流启动成功
2025-07-29 17:59:44 [INFO] ✅ 推理请求发送成功