Рубрики
Без рубрики

Бережливый мониторинг производственного кода

В этом учебнике показано простое и понятное решение для хранения журналов производственного приложения.

Автор оригинала: Pietro Grandinetti PhD.

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

В конце концов, у вас будет:

  • Научился использовать Python logging и at exit для интеграции простого, но довольно надежного шаблона мониторинга в ваш код.
  • Получил шаблон скрипта через GitHub’s gists.

Обзор вариантов использования

У меня есть очень реалистичный вариант использования: мониторинг сервера, который выполняет фоновые задания в виде сценариев.

Чем они могут быть, если говорить более конкретно?

  • Скрипты для предварительного расчета результатов дорогостоящих запросов к базе данных, чтобы избежать вычисления их в режиме реального времени (например, в обработчике запросов API).
  • Заряжайте пользователей подписками!
  • Отправляйте пользователям электронную почту для получения обновлений, уведомлений и многого другого.

Это всего лишь несколько примеров очень распространенного случая: машина, работающая в облачной инфраструктуре, которая выполняет периодические задания, запланированные, например, с помощью Cron.

Производственные приложения должны быть устойчивыми, производительными и, прежде всего, измеримыми. Это очень широкая тема, которая идет от Операций разработки (DevOps) до проектирования надежности сайта (SRE), управления системами и автоматизации.

Там есть тонна больших знаний на эту тему. У Google, например, есть несколько рекомендуемых книг о том, как они работают. AWS имеет обширную документацию о том, как использовать свою удивительную инфраструктуру для мониторинга производительности приложений.

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

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

То, что обычно происходит на начальном этапе жизненного цикла нового продукта (или приложения),-это много итераций между разработчиками и бизнес-командами и, во многих случаях, ранними клиентами, которые принимают продукт. Рисунок ниже, взятый из Lean Startup , иллюстрирует эти концепции.

То, что обычно происходит на начальном этапе жизненного цикла нового продукта (или приложения),-это много итераций между разработчиками и бизнес-командами и, во многих случаях, ранними клиентами, которые принимают продукт. Рисунок ниже, взятый из || Lean Startup || , иллюстрирует эти концепции.

По моему опыту, посвящение времени разработке надлежащей производственной инфраструктуры для мониторинга того, насколько хорошо работает код приложения, изначально очень расстраивает разработчиков.

Причина в том, что само приложение меняется так быстро, что разработчикам приходится много раз перестраивать “измерительные инфраструктуры”. Это также снизит их мотивацию, что, на мой взгляд, самое худшее, что может случиться с гибкой организацией. Если мотивация команды падает, то падает и организация.

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

Во-первых, регистрируйте все

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

Каждый хороший язык программирования поставляется с средствами ведения журнала (обычно в виде модуля в стандартной библиотеке), и именно его вы должны использовать.

Существуют очень хорошие системы для управления журналами; sentry, logstash и CloudwatchLogs-это три названия, которые вы, возможно, захотите узнать больше.

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

Мы часто используем Python и обычно инициализируем ведение журнала в таком модуле:

import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s [%(threadName)s] [%(levelname)s] %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S"
    handlers=[...]  # <-------- will get back to this in 1 minute!
)
log = logging.getLogger(__name__)

Точка входа в приложение

Проще говоря, мы используем __main_ _ вызов скрипта Python. Хитрость, однако , заключается в том, что весь вызов обернут вокруг try/except , так что даже когда что-то идет не так, мы не теряем все сообщения журнала и все еще можем их анализировать.

if __name__ == '__main__':
    app_name = 'CODE_SAMPLE'
    log.debug('Starting %s', app_name)
    try:
        entrypoint(sys.argv)
    except:
        log.exception('Error on %s', app_name)
    else:
        log.debug('Done.')

Фактическая точка входа

Как вы видели в __main__ выше, логика приложения содержится в функции, вызываемой main. Эта функция действительно может быть чем угодно; в наших системах она обычно выполняет многие из этих функций:

  • Звонки в разные базы данных.
  • Вызовы различных внешних API.
  • Вызовы некоторых внутренних API (для электронной почты, геолокации и т. Д.).

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

def entrypoint(*args, **kwargs):
    y = 5 + 3
    log.debug('Computed y')
    z = y + 2
    #z = x + 2  # <---- This line has a typo that we'll use to test.
    log.debug('Computed z')

Обработчик журнала

Пришло время вернуться к объекту log . Мы хотим, чтобы он был устойчив к сбоям и ошибкам, так что даже если код каким-то образом выйдет из строя, мы все равно сможем получить журналы и сохранить их где-нибудь.

Для этого нам нужны вещи.

  1. Вместо того, чтобы печатать журналы на экран или в файл в локальной системе, давайте просто иметь string в памяти, которая хранит все сообщения журнала для текущего запуска программы. Таким образом, нам не нужно обрабатывать файлы, которые могут быть повреждены или, что еще хуже, stdout сообщения, которые просто очень трудно получить. Поскольку все журналы находятся в строке, мы можем сохранять эту строку и манипулировать ею.
  2. Должен быть способ сохранить строковый объект, содержащий журналы, независимо от того, успешно ли завершилось приложение или нет.

Первый пункт может быть достигнут с помощью модуля io в Python. Вот как изменить определение журнала.

import logging
import io # <----- New line

stringio_stream = io.StringIO() # <--- New line 

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s [%(threadName)s] [%(levelname)s] %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S"
    handlers=[logging.StreamHandler(stringio_stream)]  # <--- Changed line
)
log = logging.getLogger(__name__)

Давайте поговорим о втором пункте. Мы могли бы изменить __main__ так, чтобы он делал то, что нам нужно:

import sys

if __name__ == '__main__':
    app_name = 'CODE_SAMPLE'
    log.debug('Starting %s', app_name)
    try:
    	entrypoint(sys.argv)
    except:
        log.exception('Error on %s', app_name)
    else:
    	log.debug('Done.')
    save_logs(log) # <----- New line

Это будет работать нормально. Однако есть более приятное решение, которое работает с использованием пакета atexit , который является частью стандартной библиотеки Python.

atexit имеет функцию с именем register , которая позволяет регистрировать выполнение функции на момент завершения программы.

В принципе, независимо от того, что происходит в вашем коде (сбои, ошибки или просто прекрасное выполнение), фрагмент кода, зарегистрированный в atexit , будет выполнен непосредственно перед выходом программы.

С учетом сказанного, вот как мы используем для сохранения журналов.

import atexit

atexit.register(
    save_logs,
    body=stringio_stream.getvalue() # <-- This is the trick!
)

Что делать с журналами мониторинга?

Последним кусочком головоломки является реализация функции save_logs . Что делать в нем на самом деле, зависит от того, что проще для вас и вашей команды.

Мы сохраняем все журналы в виде файлов в корзине S3. Это довольно скудно для нас, чтобы пойти в ведро, загрузить файл, связанный с конкретным запуском приложения, и посмотреть на журналы, чтобы увидеть, если что-то пошло не так.

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

Чтобы продемонстрировать этот учебник и иметь код шаблона, который действительно работает, я буду использовать сервис cl1p.net. Это бесплатный онлайн-сервис, который позволяет каждому отправлять текст и отображать его на веб-странице в течение короткого времени.

Вот как это будет работать в функции save_logs .

import time
import requests

def save_logs(body):
    # This function should implement a robust solution
    # to store the log string.
    # E.g., it could upload a file to S3.
    # For the sake of this tutorial let's upload the string
    # to cl1p.net

    # In a real application you will want to save a file
    # with the name `app_name + timestamp`.
    #clip_name = app_name + '_' + str(int(time.time()))
    # To use it with cl1p.net we must use a fixed name
    clip_name = 'test-clip-name'
    headers = {'Content-Type': 'text/html; charset=UTF-8'}
    endpoint = 'https://api.cl1p.net/' + clip_name
    requests.post(endpoint, headers=headers, data=body)

Соединяя точки

На этом этапе вы можете соединить все фрагменты кода, и у вас будет рабочий шаблон, который вы можете расширить дальше.

Для ваших приложений вы должны изменить две части шаблона:

  1. Напишите пользовательскую логику вашего приложения в функции точка входа .
  2. Замените вызов на cl1p.net с пользовательским, более устойчивым подходом, таким как вызов функций boto3 для загрузки файла в S3.

Вот весь шаблон, и вы также можете скачать его с этого GitHub gist .

import time
import logging
import io
import atexit
import sys

import requests


stringio_stream = io.StringIO()

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s [%(threadName)s] [%(levelname)s] %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S",
    handlers=[logging.StreamHandler(stringio_stream)]
)
log = logging.getLogger(__name__)


def entrypoint(*args, **kwargs):
    # This function should contain the custom logic
    # of your application.
    # Make it as complicated as you need!
    y = 5 + 3
    log.debug('Computed y')
    z = y + 2
    #z = x + 2  # <---- This line has a typo that we'll use to test.
    log.debug('Computed z')


def save_logs(body):
    # This function should implement a robust solution
    # to store the log string.
    # E.g., it could upload a file to S3.
    # For the sake of this tutorial let's upload the string
    # to cl1p.net

    # In a real application you will want to save a file
    # with the name `app_name + timestamp`.
    #clip_name = app_name + '_' + str(int(time.time()))
    # To use it with cl1p.net we must use a fixed name
    clip_name = 'test-clip-name'
    headers = {'Content-Type': 'text/html; charset=UTF-8'}
    endpoint = 'https://api.cl1p.net/' + clip_name
    requests.post(endpoint, headers=headers, data=body)


if __name__ == '__main__':
    app_name = 'CODE_SAMPLE'
    log.debug('Starting %s', app_name)
    try:
        entrypoint(sys.argv)
    except:
        log.exception('Error on %s', app_name)
    else:
        log.debug('Done.')


atexit.register(
    save_logs,
    body=stringio_stream.getvalue() #   <-- This is the trick!
)

Тестирование шаблона

Есть два теста, которые я хотел бы сделать у вас.

Во-первых, давайте просто запустим шаблон как есть. Это займет всего одну секунду. Когда все будет закончено, идите к https://cl1p.net/test-clip-name

Удивлен? Да, это именно полная трассировка журнала вашего кода!

Скриншот с 2021-02-21 21-30-29.png

С его помощью можно сделать много интересного:

  • Прежде всего, проверьте, нет ли ошибки.
  • Проанализируйте, сколько времени проходит между каждым сообщением, чтобы выяснить, является ли какая – либо часть кода медленной.

Есть еще один тест, который, я думаю, стоит проверить. Закомментируйте строку 27 и раскомментируйте строку 28. Как вы можете видеть, это создаст ошибку в коде, потому что переменная x не определена.

Запустите код еще раз, а затем снова продолжайте https://cl1p.net/test-clip-name

Что ты видишь сейчас? Да, это снова полная ошибка журнала, но с очень полезной информацией со всей трассировкой стека!

Скриншот с 2021-02-21 21-29-36.png

Даже если приложение разбилось, мы все равно сохранили полезную информацию, чтобы исправить его.

Но самое большое преимущество в том, что мы сделали это практически без усилий! Взгляните еще раз на код: он очень, очень прост!

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

Дайте мне знать, если вы столкнетесь с какой-либо проблемой, воспроизводящей этот учебник.

Бонус: загрузите журналы в S3

Обычно я загружаю журналы в виде файла в S3. Вот функция, которую я использую (вам нужно загрузить учетные данные AWS в качестве переменных среды).

import boto3
from datetime import datetime

def save_logs(body, app_name):
    now = datetime.utcnow().strftime('%Y-%m-%dT%H:%M:%S')
    key = app_name + '_' + now
    client = boto3.client(
        's3',
        aws_access_key_id=environ['AWS_ACCESS_KEY'],
        aws_secret_access_key=environ['AWS_SECRET_KEY']
    )
    bucket = environ['S3_LOG_BUCKET']
    client.put_object(Body=body, Bucket=bucket, Key=key)