【发布时间】:2021-02-19 03:35:42
【问题描述】:
我们正在调查已部署的云运行服务的问题,向该服务发出的请求偶尔会失败并显示 StatusCodeError: 500,而云运行中没有显示上述请求的日志。
服务请求通常会产生两条日志行,详细说明请求、路由和退出代码 (POST 200 on https://service-name.a.run.app/route/...)
- 日志名称为
projects/XXX/logs/run.googleapis.com/stdout的日志由我们的应用程序生成,用于记录每个请求的服务 - 日志名称为
projects/XXX/logs/run.googleapis.com/requests的日志由云在每次请求时自动生成
当事件发生时,没有记录在案。客户端(在同一项目的 gke pod 中运行)具有失败请求的唯一日志,并带有以下消息:
StatusCodeError: 500 - "\n<html><head>\n<meta http-equiv=\"content-type\" content=\"text/html;charset=utf-8\">\n<title>500 Server Error</title>\n</head>\n<body text=#000000 bgcolor=#ffffff>\n<h1>Error: Server Error</h1>\n<h2>The server encountered an error and could not complete your request.<p>Please try again in 30 seconds.</h2>\n<h2></h2>\n</body></html>\n"
上一次事件的大致时间线:
- 14:41 - 服务按预期处理请求,每次都生成两条日志行
- 14:44 到 14:56 - 云运行日志为空,向服务发出的每个请求 (~30) 都会收到 500 错误消息
- 14:56 - 云运行终止当前运行的容器实例(例如在某些不活动之后发生),应用程序正确记录了该实例 (
[INFO] Handling signal: term) - 14:58 - Cloud run 实例化一个新容器实例并开始服务传入请求(正常记录)
事件期间没有日志,因此很难调查其原因,在此阶段,我们将不胜感激任何形式的线索。
我们的服务有另一个已知问题,可能相关也可能不相关。该服务旨在避免多个副本,因为单个副本应该能够处理负载并服务并发请求(云运行并发性 = 80),但冷启动时间相对较长(约 30 秒)。当请求高峰出现而没有可用副本时,这会导致 429 错误(因为云运行在冷启动期间将并发硬性上限限制为 1)。通过允许一些复制(当前 maxScale = 3)在一定程度上缓解了这个问题,因为每个副本都可以在冷启动期间暂停请求,但需要在客户端进行一些工作才能正确处理(冷启动后的简单重试) .
【问题讨论】:
-
您能分享您的代码以及如何登录吗?
-
不幸的是,代码本身是私有的。它是一个 python gunicorn 应用程序,通过标准打印输出用于调试目的,以及用于帖子上显示的日志行的
logging包。请注意,第二条日志行是由云运行生成的,而不是我们的应用程序,并且在事件期间也丢失了。 -
当然你的代码是私有的!但是你能清理它并有一个最小的可重现的例子吗?您的问题很奇怪,因为即使您的日志有问题,Cloud Run 平台日志也应该继续工作,它独立于您的代码!
-
您是否看到 Cloud Run 通常会在收到针对上述事件的请求时为任何容器记录的“请求日志”?
-
@guillaumeblaquiere 我没有关注应用程序代码,因为据我所知,事件发生时它不会执行(不提供请求并且不输出日志)。一个最小的例子是一个 gunicorn 应用程序,在初始化时具有 sleep(30) 和在服务请求时具有 sleep(0.1) ......正如你所说,在我看来,问题与应用程序本身无关......
标签: google-cloud-run