Отсутствуют строки журнала при записи в cloudwatch из контейнеров ECS Docker

ОБНОВЛЕНИЕ: похоже, теперь это исправлено, поэтому нет необходимости применять описанный ниже обходной путь.

Я видел такое же поведение при использовании контейнеров ECS Fargate для запуска скриптов Python - и в результате испытал такое же разочарование!

Я думаю, это связано с тем, что агент CloudWatch Logs Agent публикует события журнала партиями:

Как группируются события журнала?

Пакет становится полным и публикуется при выполнении любого из следующих условий:

1. buffer_duration количество времени прошло с момента добавления первого события журнала.

2. Накоплено менее batch_size событий журнала, но добавление нового события журнала превышает batch_size.

3. Количество событий журнала достигло batch_count.

4. События журнала из пакета не охватывают более 24 часов, но добавление нового события журнала превышает 24-часовое ограничение.

(Ссылка: https://docs.aws.amazon.com/AmazonCloudWatch/latest/logs/AgentReference.html)

Таким образом, возможное объяснение состоит в том, что события журнала буферизуются агентом, но еще не публикуются, когда задача ECS остановлена. (И если так, то это похоже на проблему ECS - любые инженеры AWS ECS, желающие высказать свое мнение по этому поводу ...?)

Кажется, что нет прямого способа обеспечить публикацию журналов, но он предполагает, что можно подождать не менее buffer_duration секунд (по умолчанию 5 секунд), и все предыдущие журналы должны быть опубликованы.

После небольшого тестирования, которое я опишу ниже, я нашел обходной путь. Сценарий оболочки 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"]

run_then_wait.sh

#!/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
"$@"

main.py

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")

Надеюсь, этот подход можно адаптировать к вашей ситуации. Вы также можете реализовать засыпание внутри своего сценария, но может быть сложнее обеспечить, чтобы это происходило независимо от того, как он завершается.

Трудно доказать, что предложенное объяснение является точным, поэтому я использовал приведенный выше код, чтобы проверить эффективность обходного пути. Тестом была исходная команда vs. run_then_wait.sh, по 30 запусков каждая. В результате проблема наблюдалась в 30% случаев против 0% соответственно. Надеюсь, это так же эффективно для вас!

Только что обратился в службу поддержки AWS по поводу этой проблемы, и вот их ответ:

...

Основываясь на этом случае, я вижу, что это происходит для контейнеров в задаче Fargate, которая быстро завершается после вывода в stdout / stderr. Похоже, это связано с тем, как работает драйвер awslogs и как Docker в Fargate взаимодействует с конечной точкой CW.

Глядя на наши внутренние заявки на то же самое, я вижу, что наша служба поддержки все еще работает над постоянным решением этой обнаруженной ошибки. К сожалению, пока неизвестно, когда будет установлено исправление. Однако я воспользовался этой возможностью, чтобы добавить этот случай во внутренний тикет, чтобы сообщить команде о подобном и попытаться ускорить процесс.

Между тем, этого можно избежать, увеличив время жизни выходящего контейнера, добавив задержку (~> 10 секунд) между выходом журнала приложения и выходом из процесса (выход из контейнера).

...

Обновление: обратились в AWS примерно 1 августа 2019 г. и сказали, что проблема устранена.

Я тоже это заметил. Это должно быть ошибка 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 я переключился с формы exec на форму оболочки ENTRYPOINT и добавил в конце 10-секундный сон.

До:

ENTRYPOINT ["java","-jar","/app.jar"]

После:

ENTRYPOINT java -jar /app.jar; sleep 10