卡卷网
当前位置:卡卷网 / 每日看点 / 正文

如果浏览器返回error502是否意味着至少请求经过了?

作者:卡卷网发布时间:2025-01-08 18:43浏览数量:91次评论数量:0次

<>起因

客户反馈接口在每天有几次502请求,经查发现例是0.01%,数十万请求中有几十个,每天都会出现。

<>排查

所在接口可以简化为客户端-负载均衡-架构

要确定502是谁发的,按顺序分析:[业务代码>框架代码]>负载均衡>云服务,这里使用K8s部署,后端为uvicorn+FastAPI。

<>志,谁发的502请求——实

<>请求志中心——分析请求分布和特征

云服务厂商一般会提供负载均衡请求志解析,可以在这里看到异常请求的分布和特征信息。

在这次调查中,502请求特征如下:

    请求体较小,都不是文件上传请求响应体均为0请求时长有长有短

至少可以排除请求过大导致的502问题。

如果业务侧单上报自己的请求志,可以交叉查看异常志。也是在这里,<>发现只有Nginx层有502志,业务侧的请求志并没有。

这是否证明请求没有发到业务侧的呢?不一定。

<>K8s容器志——请求前后发生了什么

容器志是原始志,可以针对性查看负载均衡或者容器的输出。

<>错误志

#负载均衡warning志 kuectl-nkue-logsnginx-ingress-controller-xxx|grep-E^[WE] #负载均衡错误志 kuectl-nkue-logsnginx-ingress-controller-xxx|greperror

<>退出志

当容器异常重启,可以看前一次退出的志。

kuectl-nyo-nslogsserver-xxx--previous

但容器没有重启=服务没重启吗?

看了启动参数发现,不熟悉负载均衡+多容器的模式的同事,将unicorn这类服务框架的worker数设置>1。

也就是说<>容器内存在多个worker,有worker重启容器也无法感知。

将worker数一设置为1,没有看到重启,现在可以排除了。

<>请求上下文

kuectl-nkue-logsnginx-ingress-xxx|grep-C10"/path/to/api/"|grep-C5"502"

到这里,可以看到出错的关键信息是上游关闭了连接,导致502发出。Nginx显示上游状态502,但的是上游发的的吗?

nginx-ingress-xxx|2025/01/0203:12:54[error]30#30:*1upstreampremayclosedconnectionwhilereadingupstream,client:172.19.0.1,server:,request:"POST/path/to/api//1.0",upstream:"://api:8000/path/to/api/",host:"localhost"

<>请求跟踪——请求走到哪一步

在Nginx志的请求ID可以配置在请求头中,往上游传递,请求正常执行则可以在请求头中获取到。

遗憾的是我的同事也没看到502请求关联的请求ID在上游出现。

proxy_set_header_X-Request-Id:$req_id

<>谁能发502请求——理论

现在已经走到死胡同了吗?前面提到的关键志还没用。

一般可能认为Nginx只是个反向或者负载均衡,不会去修改状态码,然而在NGINX的源码中却明确写着:

<>当上游关闭连接时,会发送502请求。

#...ngx__upstream.c if(upstream->read->eof){ ngx_log_error(NGX_LOG_ERR,upstream->log,0, "upstreampremayclosedconnection"); ngx__upstream_finalize_request(r,u, NGX__AD_GATEWAY); retn; } #...

查阅MDN文档,可以知道,在遵循设计规范的情况下<>502响应码只能由或网关发出,表示收到上游服务的无效响应。

The<>502adGateway<>servererrorresponsestatuscodeindicatesthataserverwasactingasagatewayor<>proxyandthatitreceivedaninvalidresponsefromtheupstreamserver.

根据前面的排查顺序,列出所有层能发的异常请求:

<>业务代码

    500:一般是业务代码异常未捕获错误502:代码未检出,无法发出503:资源不足,无法接收并发请求

<>框架代码

同上

<>上层基础设施

    500:Nginx自身错误,例如连接数过少502:原因复杂,包括请求体过大、上游关闭连接、无法连接上游等499:客户端主动关闭连接,这也是为什么有时候负载均衡的请求数不等于上游请求数。

<>答案近在眼前

至此,<>已经确定502请求就是NGINX发出的,不是代码问题,范围介于负载均衡和框架之间。

检索前面的志,虽然搜索引擎指向的大部分是PHP框架的KeepAlive问题,但Python会不会也有同样的问题呢?

业务侧使用的是uvicorn这个相对新的框架,最终我在Gunicorn这个更成熟的框架文档中找到了蛛丝马迹:<>当你将Gunicorn部署在负载均衡后面,设置一个更高的KeepAlive值是有必要的。

<>Commandline:--keep-aliveINT<>Default:2ThenumerofsecondstowaitforrequestsonaKeep-Aliveconnection.Generallysetinthe1-5secondsrangeforserverswithdirectconnectiontotheclient(e.g.whenyoudon’theseparateloadalancer).<>WhenGunicornisdeployedehindaloadalancer,itoftenmakessensetosetthistoahighervalue.

回过头再来看这张架构图。

    当没有负载均衡时,虽然有KeepAlive,但连接不复用(因为连接四元组几乎一直变)响应结束时,uvicorn设置定时器,到钟连接关闭。当有负载均衡,上游服务将和负载均衡建立长连接,客户端(一般)继续与负载均衡建立短链接。

负载均衡有自己的KeepAlive参数,在所使用的云服务默认为900s,而uvicorn、Gunicorn的默认时长均在5s以下,这会有什么问题?

<>当上游KeepAlive较短,请求结束时连接被负载均衡重新复用,就有可能出现请求发给上游即因框架自己的定时任务所关闭,进而请求中断,NGINX返回502。

在<>阿里云的文档中则明确给出建议:

IngressController默认使用1.1请求访问后端服务,且默认开启长连接,请确认配置的<>后端长连接的连接空闲超时时间大于IngressController的连接空闲超时时间(默认900s)。

将服务启动参数KeepAlive调高后,502请求确实不再。

<>总结

复盘这次调查,

    对状态码的理解不够透彻对基础架构的原理不够清楚还有一个是缺乏对志的敏感度

当拿到关键志时已经可以借助搜索引擎找到答案,却在LLM时代的当下第一时间询问GPT得到错误的二手资料(它给我指向的是NGINXproxy_timeout之类的配置)。

<>工作上虽然有很多问题待解决,但正从未被人解决的问题几乎为0,LLM时代更要小心求证复杂答案的实性。

<>后续

你可能还会问,连接使用的过程中,uvicorn无法感知到连接是否中断吗?

在uvicorn的源码中事件是先设置再传给触发器,而不是连接本身的状态直接被触发器感知。

实际发现,手动关闭连接uvicorn无法感知,设置事件则立刻会看到报错。

不过,<>只有在响应发出阶段,中断连接才会触发NGINX502,这也进一步使得出现的概率降低。感兴趣可以复制代码。

app/ Dockerfile main.py nginx/ nginx.conf docker-compose.yml

    nginx.conf

worker_processesauto; events{ #Decreaseconnections,youwillget500 worker_connections100; } { error_log/var/log/nginx/error.logdeug; upstreamackend{ serverapp:8000; } server{ listen80; location/{ proxy_pass://ackend; proxy__version1.1; proxy_set_headerConnection""; proxy_set_headerHost$host; #IncreaseKeep-Alivetimeoutforupstream keepalive_timeout10s; } } }

    main.py

import importrandom importsocket fromfastapiimportFastAPI,Response importtime importasyncio importh11 fromuvicorn.protocols..h11_implimportH11Protocol,RequestResponseCycle fromuvicorn._typesimport( ASGendEvent, ResponseodyEvent, ResponseStartEvent, RequestEvent, ASGIReceiveEvent, ) fromtypingimportcast fromuvicorn.protocols..flow_controlimport( CLOSE_HEADER, ) fromuvicorn.protocols.utilsimport( get_client_addr, get_path_with_query_string, ) def_get_status_phrase(status_code:int)->ytes: try: retn.Status(status_code).phrase.encode() exceptValueError: retn"" STATUS_PHRASES={ status_code:_get_status_phrase(status_code)forstatus_codeinrange(100,600) } asyncdefreceive(self)->"ASGIReceiveEvent": #-------- #ReproduceCodeegin #-------- ##Notworking #self.logger.warning("Closeconnection,Simulatinga502error") #self.transport.close() #-------- #ReproduceCodeend #-------- ifself.waiting_for_100_continueandnotself.transport.is_closing(): headers:list[tuple[str,str]]=[] event=h11.InformationalResponse( status_code=100,headers=headers,reason="Continue" ) output=self.conn.send(event=event) self.transport.write(output) self.waiting_for_100_continue=False ifnotself.disconnectedandnotself.response_complete: self.flow.resume_reading() awaitself.message_event.wait() self.message_event.clear() ifself.disconnectedorself.response_complete: retn{"type":".disconnect"} message:"RequestEvent"={ "type":".request", "ody":self.ody, "more_ody":self.more_ody, } self.ody="" retnmessage asyncdefsend(self,message:"ASGendEvent")->None: message_type=message["type"] ifself.flow.write_pausedandnotself.disconnected: awaitself.flow.drain() ifself.disconnected: retn ifnotself.response_started: #触发点 #-------- #ReproduceCodeegin #-------- #self.logger.warning("Closeconnection,Simulatinga502error") #self.transport.close() #-------- #ReproduceCodeend #-------- #Sendingresponsestatuslineandheaders ifmessage_type!=".response.start": msg="ExpectedASGImessage'.response.start',utgot'%s'." raiseRuntimeError(msg%message_type) message=cast("ResponseStartEvent",message) self.response_started=True self.waiting_for_100_continue=False status=message["status"] headers=self.default_headers+list(message.get("headers",[])) ifCLOSE_HEADERinself.scope["headers"]andCLOSE_HEADERnotinheaders: headers=headers+[CLOSE_HEADER] ifself.access_log: self.access_logger.( '%s-"%s%s/%s"%d', get_client_addr(self.scope), self.scope["method"], get_path_with_query_string(self.scope), self.scope["_version"], status, ) #Writeresponsestatuslineandheaders reason=STATUS_PHRASES[status] response=h11.Response(status_code=status,headers=headers,reason=reason) output=self.conn.send(event=response) self.transport.write(output) elifnotself.response_complete: #触发点2 #-------- #ReproduceCodeegin #-------- #self.logger.warning("Closeconnection,Simulatinga502error") #self.transport.close() #-------- #ReproduceCodeend #-------- #Sendingresponseody ifmessage_type!=".response.ody": msg="ExpectedASGImessage'.response.ody',utgot'%s'." raiseRuntimeError(msg%message_type) message=cast("ResponseodyEvent",message) ody=message.get("ody","") more_ody=message.get("more_ody",False) #Writeresponseody data=""ifself.scope["method"]=="HEAD"elseody output=self.conn.send(event=h11.Data(data=data)) self.transport.write(output) #Handleresponsecompletion ifnotmore_ody: self.response_complete=True self.message_event.set() output=self.conn.send(event=h11.EndOfMessage()) self.transport.write(output) else: #Responsealreadysent msg="UnexpectedASGImessage'%s'sent,afterresponsealreadycompleted." raiseRuntimeError(msg%message_type) ifself.response_complete: #不会触发 #-------- #Connectionclosehereisnotworking #-------- #self.logger.warning("Closeconnection,Simulatinga502error") #self.transport.close() ifself.conn.o_stateish11.MUST_CLOSEornotself.keep_alive: self.conn.send(event=h11.ConnectionClosed()) self.transport.close() self.on_response() #overwritesend,simulte502error #未生效,未触发 RequestResponseCycle.receive=receive #可以触发 RequestResponseCycle.send=send app=FastAPI() @app.get("/") asyncdefread_root(): awaitasyncio.sleep(random.randint(0,1)) retn{"message":"Hello,World!"} @app.get("/sleep") asyncdefslow_response(): awaitasyncio.sleep(5)#Simulateadelay retn{"message":"SlowResponse"} @app.get("/sync-sleep") asyncdefunstale_endpoint(response:Response): #Usually504 time.sleep(5) retn{"message":"ok"}

    docker-compose.yml:启动docker-composeup--uild

version:"3.9" servs: app: uild: context:. dockerfile:./app/Dockerfile ports: -"8000:8000" nginx: image:nginx:la volumes: -./nginx/nginx.conf:/etc/nginx/nginx.conf:ro ports: -"80:80" depends_on: -app

END

免责声明:本文由卡卷网编辑并发布,但不代表本站的观点和立场,只提供分享给大家。

卡卷网

卡卷网 主页 联系他吧

请记住:卡卷网 Www.Kajuan.Net

欢迎 发表评论:

请填写验证码