为什么CloudWatch Logs Group的某些流不完整(即,Fargate Docker Container成功退出但日志不会突然更新)?但是,在几乎所有日志组中间歇性地看到这一点,而不是每个日志流/任务运行。我正在使用1.3.0版本
Dockerfile
runs node.js or Python scripts using the CMD
command.
这些不是服务器/长时间运行的进程,我的用例要求容器在任务完成时退出。
示例Dockerfile:
FROM node:6
WORKDIR /path/to/app/
COPY package*.json ./
RUN npm install
COPY . .
CMD [ "node", "run-this-script.js" ]
当使用docker run
在本地终端上运行此命令时,所有日志都正确打印到终端的stdout / stderr。
要在Fargate上作为ECS任务运行它们,日志驱动程序将从CloudFormation模板设置为awslogs
。
...
LogConfiguration:
LogDriver: 'awslogs'
Options:
awslogs-group: !Sub '/ecs/ecs-tasks-${TaskName}'
awslogs-region: !Ref AWS::Region
awslogs-stream-prefix: ecs
...
看到有时cloduwatch日志输出不完整,我已经运行测试并检查CW Logs Limits的每个限制,并确定问题不存在。
我最初认为这是一个问题,节点js在console.log()
被刷新之前异步退出,或者该进程过早退出,但是当我使用不同的语言时也出现同样的问题 - 这让我觉得这不是问题代码,而是专门用于cloudwatch。
通过添加睡眠定时器来引起代码延迟对我没有用。
由于docker容器在任务完成后立即退出,因此日志没有足够的时间写入CWLogs,但必须有办法确保不会发生这种情况吗?
样本日志:不完整的流:
{ "message": "configs to run", "data": {"dailyConfigs":"filename.json"]}}
running for filename
完成日志流:
{ "message": "configs to run", "data": {"dailyConfigs":"filename.json"]}}
running for filename
stdout: entered query_script
... <more log lines>
stderr:
real 0m23.394s
user 0m0.008s
sys 0m0.004s
(node:1) DeprecationWarning: PG.end is deprecated - please see the upgrade guide at https://node-postgres.com/guides/upgrading
更新:现在看来是fixed,因此不需要实现下面描述的解决方法
我在使用ECS Fargate容器运行Python脚本时看到了相同的行为 - 并且产生了同样的挫败感!
我认为这是由于CloudWatch Logs Agent批量发布日志事件:
日志事件如何批处理?
批处理已满,并在满足以下任何条件时发布:
- 自添加第一个日志事件以来,
buffer_duration
已经过了一段时间。- 已经积累了少于
batch_size
的日志事件,但添加新的日志事件超过了batch_size
。- 日志事件的数量已达到
batch_count
。- 批处理中的日志事件不超过24小时,但添加新日志事件超过了24小时约束。
(参考:https://docs.aws.amazon.com/AmazonCloudWatch/latest/logs/AgentReference.html)
因此可能的解释是,日志事件由代理缓冲,但在ECS任务停止时尚未发布。 (如果是这样,那似乎是一个ECS问题 - 任何AWS ECS工程师都愿意对此有所了解......?)
似乎没有直接的方法来确保日志发布,但它确实建议可以至少等待buffer_duration
秒(默认情况下,5秒),并且应该发布任何先前的日志。
通过我将在下面描述的一些测试,这是我着手的解决方法。 shell脚本run_then_wait.sh
包装命令以触发Python脚本,以在脚本完成后添加休眠。
Dockerfile
FROM python:3.7-alpine
ADD run_then_wait.sh .
ADD main.py .
# The original command
# ENTRYPOINT ["python", "main.py"]
# To run the original command and then wait
ENTRYPOINT ["sh", "run_then_wait.sh", "python", "main.py"]
润_太狠_外套.是
#!/bin/sh
set -e
# Wait 10 seconds on exit: twice the `buffer_duration` default of 5 seconds
trap 'echo "Waiting for logs to flush to CloudWatch Logs..."; sleep 10' EXIT
# Run the given command
"$@"
卖弄.朋友
import logging
import time
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger()
if __name__ == "__main__":
# After testing some random values, had most luck to induce the
# issue by sleeping 9 seconds here; would occur ~30% of the time
time.sleep(9)
logger.info("Hello world")
希望这种方法可以适应您的情况。您也可以在脚本中实现睡眠,但是无论它如何终止都可能更加棘手。
很难证明所提出的解释是准确的,所以我使用上面的代码来测试变通方法是否有效。测试是与run_then_wait.sh
的原始命令,每次30次运行。结果是该问题在30%的时间内被观察到,而0%的时间分别被观察到。希望这对你来说同样有效!
刚刚联系AWS支持人员了解此问题,以下是他们的回复:
...
基于这种情况,我可以看到,在输出到stdout / stderr之后,Fargate任务中的容器会快速退出。它似乎与awslogs驱动程序的工作方式有关,以及Fargate中的Docker如何与CW端点通信。
看看我们的内部门票,我可以看到我们的服务团队仍在努力获得针对此报告错误的永久解决方案。不幸的是,在部署修复程序时没有共享ETA。但是,我借此机会将此案例添加到内部票证中,以通知团队类似并尝试加快流程
同时,通过在应用程序的日志记录输出和进程退出(容器的退出)之间添加延迟(〜> 10秒)来延长现有容器的生命周期,可以避免这种情况。
...
我也观察到了这一点。它必须是ECS错误?
我的解决方法(Python 3.7):
import atexit
from time import sleep
atexit.register(finalizer)
def finalizer():
logger.info("All tasks have finished. Exiting.")
# Workaround:
# Fargate will exit and final batch of CloudWatch logs will be lost
sleep(10)
将日志刷新到CloudWatch
时遇到了同样的问题。
在asavoy's回答之后,我从执行形式切换到ENTRYPOINT
的shell形式,最后加入了10秒的睡眠。
之前:
ENTRYPOINT ["java","-jar","/app.jar"]
后:
ENTRYPOINT java -jar /app.jar; sleep 10