APIPark icon indicating copy to clipboard operation
APIPark copied to clipboard

bug: 调用模型类接口,当请求速率过快时,会偶发接口返回400的报错,但是实际上模型端是处理完毕请求了的

Open ran411285752 opened this issue 3 months ago • 20 comments

Current Behavior

通过APIPark,请求xinference部署的qwen3-30b-instruct模型以及百炼平台的模型,都会偶发这个问题。

直接请求xinference或者百炼的API接口,不会接口返回出现400这个问题。

从xinference和百炼后台日志看,请求是正常响应完毕了的,响应是200,并没有报错。

Expected Behavior

请求模型接口正常返回信息

Error Logs

接口返回日志: the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection

apinto日志: [2025-09-19 14:34:44] [ERRO] [worker-127]http upstream send error: the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection [2025-09-19 14:34:44] [ERRO] [worker-127]the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection

xinference日志: 2025-09-19 14:34:31,129 xinference.core.supervisor 144 DEBUG [request b2e5656c-9522-11f0-ae73-729ef6cd8ded] Enter get_model, args: <xinference.core.supervisor.SupervisorActor object at 0x7f936217d3f0>,Qwen3-Instruct, kwargs: 2025-09-19 14:34:31,129 xinference.core.worker 144 DEBUG Enter get_model, args: <xinference.core.worker.WorkerActor object at 0x7f936217df30>, kwargs: model_uid=Qwen3-Instruct-0 2025-09-19 14:34:31,129 xinference.core.worker 144 DEBUG Leave get_model, elapsed time: 0 s 2025-09-19 14:34:31,129 xinference.core.supervisor 144 DEBUG [request b2e5656c-9522-11f0-ae73-729ef6cd8ded] Leave get_model, elapsed time: 0 s 2025-09-19 14:34:31,130 xinference.core.supervisor 144 DEBUG [request b2e58f92-9522-11f0-ae73-729ef6cd8ded] Enter describe_model, args: <xinference.core.supervisor.SupervisorActor object at 0x7f936217d3f0>,Qwen3-Instruct, kwargs: 2025-09-19 14:34:31,130 xinference.core.worker 144 DEBUG Enter describe_model, args: <xinference.core.worker.WorkerActor object at 0x7f936217df30>, kwargs: model_uid=Qwen3-Instruct-0 2025-09-19 14:34:31,130 xinference.core.worker 144 DEBUG Leave describe_model, elapsed time: 0 s 2025-09-19 14:34:31,130 xinference.core.supervisor 144 DEBUG [request b2e58f92-9522-11f0-ae73-729ef6cd8ded] Leave describe_model, elapsed time: 0 s 2025-09-19 14:34:31,131 xinference.core.model 910 DEBUG Request chat, current serve request count: -762, request limit: inf for the model Qwen3-Instruct 2025-09-19 14:34:31,131 xinference.core.model 910 DEBUG [request b2e5c85e-9522-11f0-818f-729ef6cd8ded] Enter chat, args: ModelActor(Qwen3-Instruct-0),[{'role': 'user', 'content': '随机生成一段500字的文章'}],{'stream': True, 'max_tokens': None}, kwargs: raw_params={'stream': True} 2025-09-19 14:34:31,131 xinference.model.llm.vllm.core 910 DEBUG Enter generate, prompt: <|im_start|>user 随机生成一段500字的文章<|im_end|> <|im_start|>assistant , generate config: {'stream': True, 'max_tokens': None, 'stop': ['<|endoftext|>', '<|im_start|>', '<|im_end|>'], 'stop_token_ids': [151643, 151644, 151645]} 2025-09-19 14:34:31,132 xinference.model.llm.vllm.core 910 DEBUG No max_tokens set, setting to: 262124 2025-09-19 14:34:31,132 xinference.core.model 910 DEBUG [request b2e5c85e-9522-11f0-818f-729ef6cd8ded] Leave chat, elapsed time: 0 s 2025-09-19 14:34:31,132 xinference.core.model 910 DEBUG After request chat, current serve request count: -762 for the model Qwen3-Instruct INFO 09-19 14:34:31 [async_llm_engine.py:210] Added request b2e5cc8c-9522-11f0-818f-729ef6cd8ded. INFO 09-19 14:34:31 [metrics.py:417] Avg prompt throughput: 0.5 tokens/s, Avg generation throughput: 2.3 tokens/s, Running: 1 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.0%, CPU KV cache usage: 0.0%. INFO 09-19 14:34:35 [async_llm_engine.py:178] Finished request b2e5cc8c-9522-11f0-818f-729ef6cd8ded. 2025-09-19 14:34:35,041 xinference.model.llm.vllm.core 910 INFO Generate finished, request_id: b2e5cc8c-9522-11f0-818f-729ef6cd8ded, stop reason: stop, prompt tokens: 20, completion tokens: 524, all tokens: 544

Steps to Reproduce

使用postman,高频次发送10次中等长度请求,例如:”随机生成一段500字的短片文章“

个人测试必现操作: 1、使用python脚本,并发10个API流式请求,请求APIPark的接口(Xinference和百炼都必现),发起请求后,直接中断代码请求,然后再次发起10个并发流式请求,必现400的问题,但是这个必现错误日志是: "HTTP/1.1 400 Bad Request" 2025-09-19 15:26:26,632 - ERROR - Error during request: error when reading response headers: cannot find whitespace in the first line of response "1b0\r\ndata: {"choices":[{"finish_reason":null,"delta":{"content":"秀的学生,如今却因母亲突发重病、欠下巨额医疗费,被迫签下一份神秘协议,成为寰宇集团总裁陆沉的“契约女友”。","reasoning_content":""},"index":0}],"code":null,"created":1758266783627,"id":"d77e8fc0-c3ef-4963-ba6b-68345f53551a","message":null,"model":"qwen-plus","object":"chat.completion.chunk","type":null,"usage":null}\n\n\r\n1b2\r\ndata: {"choices":[{"finish_reason":null,"delta":{"content":"\n\n是的,契约女友。\n\n传闻中,陆沉冷酷无情,手段狠辣,掌舵寰宇五年,将一个濒临破产的地产公司打造成横跨金融、","reasoning_content":""},"index":0}],"code":null,"created":1758266784395,"id":"d77e8fc0-c3ef-4963-ba6b-68345f53551a","message":null,"model":"qwen-plus","object":"chat.completion.chunk","type":null,"usage":null}\n\n\r\n1b3\r\ndata: {"choices":[{"finish_reason":null,"delta":{"content":"科技、娱乐的商业帝国。他从不参加社交活动,更不近女色,甚至有人说他性向成谜。可就在三天前,他亲自出现在医院,","reasoning_content":""},"index":0}],"code":null,"created":1758266785151,"id":"d77e8fc0-c3ef-4963-ba6b-68345f53551a","message":null,"model":"qwen-plus","object":"chat.completion.chunk","type":null,"usage":null}\n\n\r\n1a6\r\ndata: {"choices":[{"finish_reason":null,"delta":{"content":"甩出一张五千万的支票,只说了一句话:“做我三个月的女朋友,你妈能活。”\n\n林晚星别无选择。\n\n第二章:","reasoning_content":""},"index":0}],"code":null,"created":1758266785840,"id":"d77e8fc0-c3ef-4963-ba6b-68345f53551a","message":null,"model":"qwen-plus","object":"chat.completion.chunk","type":null,"usage":null}\n\n\r\n1b4\r\ndata: {"choices":[{"finish_reason":null,"delta":{"content":"冰冷的开始\n\n总统套房内,水晶吊灯洒下冷白的光。陆沉坐在真皮沙发上,一身剪裁完美的黑色西装,轮廓如刀刻般锋利。","reasoning_content":""},"index":0}],"code":null,"created":1758266786564,"id":"d77e8fc0-c3ef-4963-ba6b-68345f53551a","message":null,"model":"qwen-plus","object":"chat.completion.chunk","type":null,"usage":null}\n\n\r\n". Buffer size=2194, contents: "1b0\r\ndata: {"choices":[{"finish_reason":null,"delta":{"content":"秀的学生,如今却因母亲突发重病、欠下巨额医疗费,被迫签下一份神秘协议,成为寰宇集团总裁陆沉"..."ntent":""},"index":0}],"code":null,"created":1758266786564,"id":"d77e8fc0-c3ef-4963-ba6b-68345f53551a","message":null,"model":"qwen-plus","object":"chat.completion.chunk","type":null,"usage":null}\n\n\r\n"

2、使用python脚本,并发10个API非流式请求,请求APIPark的接口(Xinference和百炼都必现),发起请求后,直接中断代码请求,然后再次发起10个并发非流式请求,必现400的问题,这个必现错误日志就是the server closed connection before returning the first response byte: [请求9] 完成 [请求4] 完成 请求失败,状态码: 400 the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection [请求1] 完成 请求失败,状态码: 400 the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection [请求2] 完成 {"id":"chat27da1986-952c-11f0-818f-729ef6cd8ded","object":"chat.completion","created":1758267737,"model":"Qwen3-Instruct","choices":[{"index":0,"message":{"role":"assistant","content":"初冬的清晨,雾像一层薄纱,轻轻覆在小镇的屋顶上。林晚推开窗户,冷风裹着湿气扑进来,她缩了缩脖子,轻轻呵出一口白气。今天是她辞去工作的第一天,也是她第一次决定为自己而活。\n\n她拎起帆布包,里面有三本旧书、一张手绘地图,还有一张写满梦想的纸条——“去海边,看日出,写一本自己的小说。”她不知道路有多远,也不知道能不能做到,但她知道,再不走,就真的老了。\n\n沿着石板路慢行,两旁的老屋斑驳,墙上爬满了青藤。街角的早餐铺飘来油条的香气,老板娘认得她,笑着递来一碗热豆浆:“丫头,走远路啊?”林晚点点头,笑着道谢。阳光渐渐穿透云层,像撒了一地碎金。\n\n午时,她坐在湖边的长椅上翻书。一阵风过,书页哗啦作响,一张泛黄的照片从书页中滑落——是她儿时和母亲在海边的合影,那时的笑容清澈得像海浪。她心头一颤,眼眶微红。原来,她一直想追寻的,不只是远方,更是那个被遗忘的自己。\n\n傍晚,她登上了通往海边的山坡。夕阳熔金,海面如镜,波光粼粼。她脱下鞋,赤脚踩在温热的沙地上,一步步走向海水。浪花温柔地舔舐脚踝,像在低语:“你终于来了。”\n\n夜幕降临,她坐在沙滩上,翻开日记本,写下第一行字:“今天,我看见了海,也看见了自己。”远处,城市的灯火亮起,而她的世界,刚刚开始。\n\n风继续吹着,带着咸涩与自由的气息。她轻声说:“我来了,不是迟到,只是刚刚开始。”"},"finish_reason":"stop"}],"usage":{"prompt_tokens":19,"completion_tokens":414,"total_tokens":433}}

Environment

容器部署

  • ApiPark version: apipark/apipark:v1.9.3-beta
  • Operating system (run uname -a): Linux ubuntu-template 6.14.0-29-24.04.1-Ubuntu

ran411285752 avatar Sep 19 '25 07:09 ran411285752

收到您的反馈,我们尽快排查看看能不能复现,十分感谢

Dot-Liu avatar Sep 19 '25 08:09 Dot-Liu

该问题已复现,和并发关系不大,原因是客户端关闭了和网关的连接,网关没有及时丢弃该请求 导致下一次请求时使用了旧的上下文,该问题我们尽快修复,感谢您的反馈

Dot-Liu avatar Sep 26 '25 03:09 Dot-Liu

当前问题已修复,请更新apinto镜像到0.22.14

Dot-Liu avatar Sep 28 '25 01:09 Dot-Liu

已更新,暂未发现问题

ran411285752 avatar Sep 30 '25 06:09 ran411285752

当前问题已修复,请更新apinto镜像到0.22.14

根据最近一周的使用情况来看,apinto镜像到[0.22.14],还是有400的情况发生

Image

ran411285752 avatar Oct 11 '25 07:10 ran411285752

还是会有问题,如果jemeter压测,几十个并发就出出现这个报错

konmi avatar Oct 15 '25 11:10 konmi

The problem’s still happening. You can get the error two ways—either fire up a new LLM chat right after wrapping the last one up, or when the LLM’s working on an automated dev task (it’ll pop up mid-process).

CJXB avatar Oct 18 '25 08:10 CJXB

好的,我再尝试复现看看

Dot-Liu avatar Oct 21 '25 03:10 Dot-Liu

当前问题已修复,请更新apinto镜像到0.22.14

根据最近一周的使用情况来看,apinto镜像到[0.22.14],还是有400的情况发生

Image

尝试复现了下,之前的状态码返回400,报错:the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection的问题已经解决

现在还出现400,看返回是超时了

Image

这个状态码赋值错误的问题今天处理完后更新,对应的状态码应该是504

Dot-Liu avatar Oct 24 '25 07:10 Dot-Liu

当前问题已修复,请更新apinto镜像到0.22.14

根据最近一周的使用情况来看,apinto镜像到[0.22.14],还是有400的情况发生 Image

尝试复现了下,之前的状态码返回400,报错:the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection的问题已经解决

现在还出现400,看返回是超时了

Image 这个状态码赋值错误的问题今天处理完后更新,对应的状态码应该是504

这里说的‘the server closed connection’已解决指的是上一个版本已解决,还是下个发布版本解决哦? Image

ran411285752 avatar Oct 28 '25 01:10 ran411285752

当前问题已修复,请更新apinto镜像到0.22.14

根据最近一周的使用情况来看,apinto镜像到[0.22.14],还是有400的情况发生 Image

尝试复现了下,之前的状态码返回400,报错:the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection的问题已经解决 现在还出现400,看返回是超时了 Image 这个状态码赋值错误的问题今天处理完后更新,对应的状态码应该是504

这里说的‘the server closed connection’已解决指的是上一个版本已解决,还是下个发布版本解决哦? Image

在0.22.14版本已解决,0.22.15更新的是状态码错误的问题

Dot-Liu avatar Oct 28 '25 02:10 Dot-Liu

当前问题已修复,请更新apinto镜像到0.22.14

根据最近一周的使用情况来看,apinto镜像到[0.22.14],还是有400的情况发生 Image

尝试复现了下,之前的状态码返回400,报错:the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection的问题已经解决 现在还出现400,看返回是超时了 Image 这个状态码赋值错误的问题今天处理完后更新,对应的状态码应该是504

这里说的‘the server closed connection’已解决指的是上一个版本已解决,还是下个发布版本解决哦? Image

在0.22.14版本已解决,0.22.15更新的是状态码错误的问题

我的也是切到0.22.14版本,还是会400,出现概率很高,该问题应该并未彻底修复。可以流量稍微大(qps>50)压测试试

konmi avatar Oct 28 '25 02:10 konmi

当前问题已修复,请更新apinto镜像到0.22.14

根据最近一周的使用情况来看,apinto镜像到[0.22.14],还是有400的情况发生 Image

尝试复现了下,之前的状态码返回400,报错:the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection的问题已经解决 现在还出现400,看返回是超时了 Image 这个状态码赋值错误的问题今天处理完后更新,对应的状态码应该是504

这里说的‘the server closed connection’已解决指的是上一个版本已解决,还是下个发布版本解决哦? Image

在0.22.14版本已解决,0.22.15更新的是状态码错误的问题

我的也是切到0.22.14版本,还是会400,出现概率很高,该问题应该并未彻底修复。可以流量稍微大(qps>50)压测试试

@Dot-Liu 是的,如上所说,0.22.14版本并未完全解决该问题,如果有时间,麻烦可以再排查一下'the server closed connection '的问题

ran411285752 avatar Oct 28 '25 02:10 ran411285752

当前问题已修复,请更新apinto镜像到0.22.14

根据最近一周的使用情况来看,apinto镜像到[0.22.14],还是有400的情况发生 Image

尝试复现了下,之前的状态码返回400,报错:the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection的问题已经解决 现在还出现400,看返回是超时了 Image 这个状态码赋值错误的问题今天处理完后更新,对应的状态码应该是504

这里说的‘the server closed connection’已解决指的是上一个版本已解决,还是下个发布版本解决哦? Image

在0.22.14版本已解决,0.22.15更新的是状态码错误的问题

我的也是切到0.22.14版本,还是会400,出现概率很高,该问题应该并未彻底修复。可以流量稍微大(qps>50)压测试试

@Dot-Liu 是的,如上所说,0.22.14版本并未完全解决该问题,如果有时间,麻烦可以再排查一下'the server closed connection '的问题

刚我将gateway镜像切到0.22.15版本后,问题也依然在

konmi avatar Oct 28 '25 02:10 konmi

麻烦提供一下报错截图,我尝试了jmeter和自己写脚本,均未再出现该问题 确认下网关部分是否仍然是相同的报错,看您这里的错误,貌似是客户端的报错?

Dot-Liu avatar Oct 28 '25 02:10 Dot-Liu

麻烦提供一下报错截图,我尝试了jmeter和自己写脚本,均未再出现该问题 确认下网关部分是否仍然是相同的报错,看您这里的错误,貌似是客户端的报错?

上面是我自己写的python压测脚本,接口是调用的apipark发布的AI服务,下面是apinto的截图

Image

ran411285752 avatar Oct 28 '25 02:10 ran411285752

麻烦提供一下报错截图,我尝试了jmeter和自己写脚本,均未再出现该问题 确认下网关部分是否仍然是相同的报错,看您这里的错误,貌似是客户端的报错?

并发是多少呢,qps<40不容易出现。而且不仅是代理llm接口不行,代理restful http接口也有这个问题的,请知悉

konmi avatar Oct 28 '25 02:10 konmi

麻烦提供一下报错截图,我尝试了jmeter和自己写脚本,均未再出现该问题 确认下网关部分是否仍然是相同的报错,看您这里的错误,貌似是客户端的报错?

上面是我自己写的python压测脚本,接口是调用的apipark发布的AI服务,下面是apinto的截图

Image

@Dot-Liu 补充一下这个测试复现的方法: 1、使用python发起5个并发的模型请求,然后在请求处理完之前直接关闭掉。当然,我这里是为了复现,才这样操作的,正常的情况就如上面另外一个伙伴说的,不只是AI服务请求,REST服务在正常的调用以及正常结束的情况下,高并发的时候也有概率发生400的the server closed connection。 2、关闭请求后立即再发起5个并发请求,大概率必现。

xinference请求日志如下,从这个日志里面可以看出,第二次的5个请求都是成功响应生成完毕了的 xinference_log.txt

apinto的日志: Image

ran411285752 avatar Oct 28 '25 03:10 ran411285752

麻烦提供一下报错截图,我尝试了jmeter和自己写脚本,均未再出现该问题 确认下网关部分是否仍然是相同的报错,看您这里的错误,貌似是客户端的报错?

上面是我自己写的python压测脚本,接口是调用的apipark发布的AI服务,下面是apinto的截图 Image

@Dot-Liu 补充一下这个测试复现的方法: 1、使用python发起5个并发的模型请求,然后在请求处理完之前直接关闭掉。当然,我这里是为了复现,才这样操作的,正常的情况就如上面另外一个伙伴说的,不只是AI服务请求,REST服务在正常的调用以及正常结束的情况下,高并发的时候也有概率发生400的the server closed connection。 2、关闭请求后立即再发起5个并发请求,大概率必现。

xinference请求日志如下,从这个日志里面可以看出,第二次的5个请求都是成功响应生成完毕了的 xinference_log.txt

apinto的日志: Image

嗯,你说的这个方法我在0.22.13版本必现

现在使用了jmeter也没有复现,并发情况如下图

Image

结果如下:

Image

0.22.14开始,这个问题就一直没出现,模拟了开始测试后关闭再重新执行也没有出现

我再尝试复现看看,后续可能需要远程您那边看看

Dot-Liu avatar Oct 28 '25 03:10 Dot-Liu

麻烦提供一下报错截图,我尝试了jmeter和自己写脚本,均未再出现该问题 确认下网关部分是否仍然是相同的报错,看您这里的错误,貌似是客户端的报错?

上面是我自己写的python压测脚本,接口是调用的apipark发布的AI服务,下面是apinto的截图 Image

@Dot-Liu 补充一下这个测试复现的方法: 1、使用python发起5个并发的模型请求,然后在请求处理完之前直接关闭掉。当然,我这里是为了复现,才这样操作的,正常的情况就如上面另外一个伙伴说的,不只是AI服务请求,REST服务在正常的调用以及正常结束的情况下,高并发的时候也有概率发生400的the server closed connection。 2、关闭请求后立即再发起5个并发请求,大概率必现。 xinference请求日志如下,从这个日志里面可以看出,第二次的5个请求都是成功响应生成完毕了的 xinference_log.txt apinto的日志: Image

嗯,你说的这个方法我在0.22.13版本必现

现在使用了jmeter也没有复现,并发情况如下图

Image 结果如下: Image 0.22.14开始,这个问题就一直没出现,模拟了开始测试后关闭再重新执行也没有出现

我再尝试复现看看,后续可能需要远程您那边看看

好的,如果需要远程,可以wx联系我,我在wx群里,搜索“迷”

ran411285752 avatar Oct 29 '25 06:10 ran411285752