英文:
Google Cloud Working not working with Gunicorn
问题
直到现在我一直直接使用uvicorn来运行在Render上启用了Google云日志记录的fastapi应用程序:
```python
def configure_logging():
# 重置根记录器配置
logging.root.handlers = []
logging.root.setLevel(level)
stream_handler = logging.StreamHandler(sys.stdout)
stream_handler.setFormatter(ConsoleFormatter(fmt=LOG_FORMAT, access_fmt=ACCESS_FORMAT))
stream_handler.setLevel(level)
logging.root.addHandler(stream_handler)
logging.root.info(
f"/etc/secrets/google-service-account.json 存在? {os.path.exists('/etc/secrets/google-service-account.json')}"
)
gcp_client = google_logging.Client.from_service_account_json("/etc/secrets/google-service-account.json")
gcp_client.setup_logging(log_level=level, labels={"source": "render", "external": "true"})
并且我有一个用于测试日志记录的端点,如下所示:
# main.py
logging.configure_logging()
app = FastAPI()
app.include_router(healthcheck_router.router)
# healthcheck_router.py
from fastapi import APIRouter
import logging as py_logging
from logging_tree import printout
from easel.api.common import logging
log = logging.get_logger(__name__)
router = APIRouter()
@router.get("/healthcheck")
async def healthcheck():
log.info("Test log")
log.info(f"Py Logging root handlers: {py_logging.root.handlers}")
printout()
return {"healthy": True}
这一切都很顺利,我的日志在Google Cloud Logging中显示为带有标签:'source': 'render',直到我决定像在fastapi网站上推荐的那样使用带有Uvicorn工作进程的Gunicorn:https://fastapi.tiangolo.com/deployment/server-workers/
现在使用gunicorn时,我是这样运行它的:
gunicorn --bind '0.0.0.0:10000' -w 1 -k uvicorn.workers.UvicornWorker easel.api.main:app
我可以看到日志正常地打印到stdout,使用我的ConsoleFormatter,但是日志没有出现在Google Cloud Logging中(无论是否带有标签)... 当我恢复到只使用uvicorn时,它又可以正常工作,但是由于其他原因,无法在没有gunicorn的情况下运行。
Python v3.8, Uvicorn 0.22.0, Gunicorn v20.1.0, google-cloud-logging v3.5.0
我尝试在该系统上运行Python解释器并实例化一个记录器,结果如预期般工作,并且我的日志出现在GCL中。
我已经三次检查了密钥文件是否存在。
我尝试使用logging_tree库,以查看是否由于某种原因gunicorn禁用了我的记录器,但是在带有gunicorn和不带gunicorn时,记录树输出没有显著差异。
不幸的是,由于它总是在macOS上崩溃(似乎与macOS有些问题),我无法在本地运行gunicorn,所以我必须依赖于在Render上运行时调试这个问题。
英文:
Up until now I've been using uvicorn directly to run a fastapi app running on Render which has google cloud logging enabled as such:
def configure_logging():
# Reset root logger config
logging.root.handlers = []
logging.root.setLevel(level)
stream_handler = logging.StreamHandler(sys.stdout)
stream_handler.setFormatter(ConsoleFormatter(fmt=LOG_FORMAT, access_fmt=ACCESS_FORMAT))
stream_handler.setLevel(level)
logging.root.addHandler(stream_handler)
logging.root.info(
f"/etc/secrets/google-service-account.json exists? {os.path.exists('/etc/secrets/google-service-account.json')}"
)
gcp_client = google_logging.Client.from_service_account_json("/etc/secrets/google-service-account.json")
gcp_client.setup_logging(log_level=level, labels={"source": "render", "external": "true"})
And I have an endpoint like the following to test the logging:
# main.py
logging.configure_logging()
app = FastAPI()
app.include_router(healthcheck_router.router)
# healthcheck_router.py
from fastapi import APIRouter
import logging as py_logging
from logging_tree import printout
from easel.api.common import logging
log = logging.get_logger(__name__)
router = APIRouter()
@router.get("/healthcheck")
async def healthcheck():
log.info("Test log")
log.info(f"Py Logging root handlers: {py_logging.root.handlers}")
printout()
return {"healthy": True}
This was all working fine with my logs showing up in Google Cloud Logging with the label: 'source': 'render' until I decided to run Gunicorn with Uvicorn workers as they recommend on the fastapi website: https://fastapi.tiangolo.com/deployment/server-workers/
Now with gunicorn i'm running it as follows:
gunicorn --bind '0.0.0.0:10000' -w 1 -k uvicorn.workers.UvicornWorker easel.api.main:app
I can see the logs getting printed to stdout using my ConsoleFormatter totally fine, however the logs arent showing up in Google Cloud Logging (with the label or without)... When I revert it to just using uvicorn it works again, unfortunately running without gunicorn is not possible due to other reasons.
Python v3.8, Uvicorn 0.22.0, Gunicorn v20.1.0, google-cloud-logging v3.5.0
I've tried running a python interpreter on the box and instantiating a logger, that works as expected and my logs show up in GCL.
I've triple checked that the secrets file is present.
I've tried using the logging_tree library to see if for some reason gunicorn is disabling my loggers, however there is no significant difference between the logging tree output with and without gunicorn.
Unfortunately I am not able to run gunicorn locally due to it always crashing with a segfault (seems to be some issue with macos) so i have to rely on debugging this on the running box on Render.
答案1
得分: 0
我找到了问题。这是因为 logging.configure_logging
在 gunicorn 主进程中运行,而且其中包含的代码会在已配置日志的情况下不重新配置。
根据 https://pythondev.readthedocs.io/fork.html#:~:text=Forking%20a%20process%20creates%20a,parent%20and%20the%20child%20process 的说明,在使用进程时,除了主线程以外的所有线程都会立即被终止,而 Google Cloud Logging 库默认会在后台线程中发布日志,因此日志会被收集但在工作进程中永远不会发布。
解决此问题的方法之一是始终允许重新配置日志,或者根据配置它的进程 PID 仔细处理禁用日志重新配置(即在不同进程中配置时允许重新配置),或者您可以只使用 Google 库中的 SyncTransport,该库不使用后台工作线程池。
英文:
I found the issue.. Its because logging.configure_logging
was running in the gunicorn master process, and it contains code to not reconfigure logging if it was already configured.
According to https://pythondev.readthedocs.io/fork.html#:~:text=Forking%20a%20process%20creates%20a,parent%20and%20the%20child%20process when you work a process, all threads but the main threads are immediately killed, and the Google Cloud Logging library by default publishes logs in a background thread, therefore logs were getting collected but never published in the worker processes.
A solution to this is either to always allow reconfiguring logging, or to be careful about disabling log reconfiguration based on the process pid it was configured in (aka allow reconfiguring if it was configured in a different process), or you can just use the SyncTransport in the google library which doesnt use the background worker pool.
通过集体智慧和协作来改善编程学习和解决问题的方式。致力于成为全球开发者共同参与的知识库,让每个人都能够通过互相帮助和分享经验来进步。
评论