Логируются что это значит
Что такое логирование?
Известно, что программисты проводят много времени, отлаживая свои программы, пытаясь разобраться, почему они не работают — или работают неправильно. Когда говорят про отладку, обычно подразумевают либо отладочную печать, либо использование специальных программ – дебагеров. С их помощью отслеживается выполнение кода по шагам, во время которого видно, как меняется содержимое переменных. Эти способы хорошо работают в небольших программах, но в реальных приложениях быстро становятся неэффективными.
Сложность реальных приложений
Возьмем для примера типичный сайт. Что он в себя включает?
И это только самый простой случай. Реальность же значительно сложнее: множество разноплановых серверов, системы кеширования (ускорения доступа), асинхронный код, очереди, внешние сервисы, облачные сервисы. Все это выглядит как многослойный пирог, внутри которого где-то работает нами написанный код. И этот код составляет лишь небольшую часть всего происходящего. Как в такой ситуации понять, на каком этапе был сбой, или все пошло не по плану? Для этого, как минимум, нужно определить, в каком слое произошла ошибка. Но даже это не самое сложное. Об ошибках в работающем приложении узнают не сразу, а уже потом, — когда ошибка случилась и, иногда, больше не воспроизводится.
Логирование
И для всего этого многообразия систем существует единое решение — логирование. В простейшем случае логирование сводится к файлу на диске, куда разные программы записывают (логируют) свои действия во время работы. Такой файл называют логом или журналом. Как правило, внутри лога одна строчка соответствует одному действию.
Выше небольшой кусок лога веб-сервера Хекслета. Из него видно ip-адрес, с которого выполнялся запрос на страницу и какие ресурсы загружались, метод HTTP, ответ бекенда (кода) и размер тела ответа в HTTP. Очень важно наличие даты. Благодаря ей всегда можно найти лог за конкретный период, например на то время, когда возникла ошибка. Для этого логи грепают:
Когда программисты только начинают свой путь, они, часто не зная причину ошибки, опускают руки и говорят «я не знаю, что случилось, и что делать». Опытный же разработчик всегда первым делом говорит «а что в логах?». Анализировать логи — один из базовых навыков в разработке. В любой непонятной ситуации нужно смотреть логи. Логи пишут все программы без исключения, но делают это по-разному и в разные места. Чтобы точно узнать, куда и как, нужно идти в документацию конкретной программы и читать соответствующий раздел документации. Вот несколько примеров:
Многие программы логируют прямо в консоль, например Webpack показывает процесс и результаты сборки:
Во фронтенде файлов нет, поэтому логируют либо прямо в консоль, либо к себе в бекенды (что сложно), либо в специализированные сервисы, такие как LogRocket.
Уровни логирования
Чем больше информации выводится в логах, тем лучше и проще отладка, но когда данных слишком много, то в них тяжело искать нужное. В особо сложных случаях логи могут генерироваться с огромной скоростью и в гигантских размерах. Работать в такой ситуации нелегко. Чтобы как-то сгладить ситуацию, системы логирования вводят разные уровни. Обычно это:
Поддержка уровней осуществляется двумя способами. Во-первых, внутри самой программы расставляют вызовы библиотеки логирования в соответствии с уровнями. Если произошла ошибка, то логируем как error, если это отладочная информация, которая не нужна в обычной ситуации, то уровень debug.
Во-вторых, во время запуска программы указывается уровень логирования, необходимый в конкретной ситуации. По умолчанию используется уровень info, который используется для описания каких-то ключевых и важных вещей. При таком уровне будут выводиться и warning, и error. Если поставить уровень error, то будут выводиться только ошибки. А если debug, то мы получим лог, максимально наполненный данными. Обычно debug приводит к многократному росту выводимой информации.
Уровни логирования, обычно, выставляются через переменную окружения во время запуска программы. Например, так:
Существует и другой подход, основанный не на уровнях, а на пространствах имен. Этот подход получил широкое распространение в JS-среде, и является там основным. Фактически, он построен вокруг одной единственной библиотеки debug для логирования, которой пронизаны практически все JavaScript-библиотеки как на фронтенде, так и на бекенде.
Принцип работы здесь такой. Под нужную ситуацию создается специализированная функция логирования с указанием пространства имен, которая затем используется для всех событий одного процесса. В итоге библиотека позволяет легко отфильтровать только нужные записи, соответствующие нужному пространству.
Запуск с нужным пространством:
Ротация логов
Со временем количество логов становится большим, и с ними нужно что-то делать. Для этого используется ротация логов. Иногда за это отвечает сама программа, но чаще — внешнее приложение, задачей которого является чистка. Эта программа по необходимости разбивает логи на более мелкие файлы, сжимает, перемещает и, если нужно, удаляет. Подобная система встроена в любую операционную систему для работы с логами самой системы и внешних программ, которые могут встраиваться в нее.
С веб-сайтами все еще сложнее. Даже на небольших проектах используется несколько серверов, на каждом из которых свои логи. А в крупных проектах тысячи серверов. Для управления такими системы созданы специализированные программы, которые следят за логами на всех машинах, скачивают их, складывают в заточенные под логи базы данных и предоставляют удобный способ поиска по ним.
Здесь тоже есть несколько путей. Можно воспользоваться готовыми решениями, такими как DataDog Logging, либо устанавливать и настраивать все самостоятельно через, например, ELK Stack
Логирование или как вести летопись работы программы
Написали программу с применением нейросети, но она выдает кучу ошибок? Где потом искать эти ошибки? Как структурировать полученную информацию?
Помочь с поиском ошибок может логирование — группа методов для сбора и сохранения информации о работе программы. Всю интересующую нас информацию мы можем записывать в текстовые файлы и потом их обрабатывать. К примеру, вот таким образом в случае деления на 0:
Тогда консоль нам покажет следующее:
А в логе с файлом увидим:
Конечно, реализовать самостоятельно такой способ — просто, и многие этим пользуются. Но у него тоже есть минус: если проект большой, надо не забывать придерживаться определенного формата их заполнения.
Но Python же один из самых дружелюбных языков.) Разработчики уже подумали о нас и создали хорошую библиотеку «logging».
Для работы с ней нам необходимо импортировать библиотеку logging и указать основные параметры. Всего параметров для настройки 6.
Так же существует 5 уровней логирования информации: от DEBUG (отладка) до critical (критичные ошибки).
На этом можно закончить с теорией, и перейдем к практике.
Теперь мы будем логировать нашу функцию деления уже с учетом модуля logging и попытаемся собрать максимум информации о ее работе. Давайте рассмотрим код нашего простенького скрипта, но уже с учетом использования логов.
Как мы видим он немного увеличился в размерах, но при этом, для записи также использует лишь одна строчка.
После – мы указываем уровень лога и имя файла, в который мы будем его записывать:
В конце нам надо создать формат записи, в котором мы укажем: время записи, имя скрипта, названия уровня и само сообщение. Остается только применить данный формат для нашего «логгера».
Вот, на этом и все) В дальнейшем мы можем использовать наш логгер простым вызовом logger.info(‘Division’) или в случае описания ошибки logger.error(error_text). По окончанию работы скрипта данные будут сохранены в файл ‘data.log’.
А теперь посмотрим, что мы получили в логе:
Запись со временем, уровнем и сообщением! Такой лог, во-первых – удобно читать, а, во-вторых – удобно обрабатывать!
Использование модуля «logger» на маленьких программах, может, и не заметно, а вот на больших польза становится очевидна. Особенно, если эти логи в дальнейшем нуждаются в обработке, например, для Process Mining-а.
Вот таким простым способом мы с вами научились делать понятную и удобную запись логов в нашем скрипте!
Время признаваться. Я абсолютно влюблена в сингапурское правительство.
Гособвинение считает, что Петров продолжал управлять своей компанией и получать от неё доход.
Почта России подвела итоги 2021 года.
Сооснователь магазина по продаже велосипедов CityCycle Владимир Лосинский рассказывает о том, какие ошибки они допустили почти за 9 лет ведения бизнеса и как их можно было избежать.
Зачем бизнесу соревнования для разработчиков и как получить от них максимум пользы для всех.
Компания будет развивать foodtech-направлении расширит производство.
Как оценить эффективность продвижения по ключевым запросам? Для этого у нас появился новый индекс, отражающий динамику ранжирования вашего приложения. Мы расширили возможности анализа по позициям в разделе Ranking. Добавили новую метрику Installs, обновили Text Editor и переработали меню.
По условиям тарифа стоимость снятия наличных за границей складывается из комиссии банка, владельца банкомата и комиссии 2% банка #Tinkoff @Тинькофф.
Декабрь — время итогов года. В том числе и финансовых. Традиционно мы упрощаем последнюю задачу для клиентов — делаем спецпроект, который помогает в ретроспективе посмотреть на свои расходы, категории покупок, любимые товары, магазины и не только. И в этом году мы снова сделали все немного иначе. Рассказываем, что именно, и причем здесь…
Логирование как способ отлаживать код
Почему так важно запретить самому себе отладку руками?
Когда вы отлаживаете программу, то вы, сами того не осознавая, думаете что за один отладочный сеанс исправите все проблемы, возникшие в рамках этой задачи. Но наша недальновидность не хочет верить в то, что на самом деле там не одна проблема, а несколько. И за один отладочный сеанс не получится решить все эти проблемы.
Поэтому вам надо будет несколько раз запускать этот код в отладочном режиме, проводя часы отладки над одним и тем же куском кода. И это только вы один столько времени потратили над этой частью программы. Каждый член команды, кому «посчастливится» работать с этим кодом, будет вынужден прожить ту же самую историю, которую прожили вы.
Я уже не говорю о том, что люди в командах меняются, команды меняются и так далее. Человеко-часы уходят на одно и то же. Перестаньте делать это. Я серьёзно. Возьмите ответственность за других людей на себя. Помогите им не переживать тот же самый участок вашей жизни.
Проблематика: Сложно отлаживать составной код
Возможный алгоритм решения проблемы:
Таким образом, вы избавляете других людей от отладки этого кода, т.к. если возникнет проблема, то человек посмотрит ваши логи и поймёт в чём причина. Логировать стоит только важные участки алгоритма.
Давайте посмотрим пример. Вы знаете, что по отдельности все реализации интерфейсов работают (т.к. написаны тесты, доказывающие это). Но при взаимодействии всего вместе возникает некорректное поведение. Что вам нужно? Нужно логировать ответы от «корректных» интерфейсов:
В этом примере видно, как мы трассируем отдельные части алгоритма для того, чтобы можно было зафиксировать тот или иной этап его выполнения. Посмотрев на логи, станет ясно в чём причина. В реальной жизни весь этот алгоритм стоило бы разбить на отдельные методы, но суть от этого не меняется.
Всё это в разы ускоряет написание кода. Вам не нужно бежать по циклу с F10 для того, чтобы понять на какой итерации цикла возникла проблема. Просто залогируйте состояние нужных вам объектов при определённых условиях на определённой итерации цикла.
В конечном итоге вы оставляете важные логи и удаляете побочные логи, например, где вы узнавали состояние объекта на определённой итерации цикла. Такие логи не помогут вашим коллегам, т.к. вы, скорее всего, уже поняли проблему некорректного алгоритма и исправили её. Если нет, то ведите разработку в вашей ветке до тех пор, пока не найдёте в чём причина и не исправите проблему. А вот логи, которые записывают важные результаты от выполнения других алгоритмов, понадобятся всем. Поэтому их стоит оставить.
Что если нам не нужен этот мусор? В таком случае выполняйте трассировку только в рамках отладки, а затем подчищайте за собой.
Как разобраться с логированием: гайд для начинающих
Этот материал мы ориентировали на тех, кто в первый раз сталкивается с логированием серверных служб и web-серверов. Познакомим с уровнями логирования, расскажем об основных типах логов и перечислим инструменты для работы с ними.
Зачем оно вообще нужно, это логирование?
На анализе логов базируется работа большинства ИТ-специалистов. Администраторы ищут в файлах логирования причины сбоя сервиса. Разработчики опираются на логи, чтобы локализовать и устранить ошибки приложения или веб-сайта. Служба безопасности по логам, как по физическим уликам, определяет вид взлома, оценивает нанесенный ущерб и даже может идентифицировать взломщика. Вот почему логирование мы рекомендуем отладить в первую очередь: в любой непонятной ситуации ответ на вопрос вы будете искать в логах!
Уровни логирования
В идеале логи пишутся во время работы всех IT-систем, однако если писать все подряд и «складывать в кучу», полезная информация превратится в хаос. Чтобы упростить поиск и чтение логов, их делят на уровни. Основных четыре:
Debug — запись масштабных переходов состояний, например, обращение к базе данных, старт/пауза сервиса, успешная обработка записи и пр.
Warning — нештатная ситуация, потенциальная проблема, может быть странный формат запроса или некорректный параметр вызова.
Error — типичная ошибка.
Fatal — тотальный сбой работоспособности, когда нет доступа к базе данных или сети, сервису не хватает места на жестком диске.
Дополнительно файл логирования может расширяться записями еще двух уровней:
Trace — пошаговые записи процесса. Полезен, когда сложно локализовать ошибку.
Info — общая информация о работе службы или сервиса.
Работа с уровнями логирования регламентируется методическими документами и внутренними правилами организации. В них может определяться соответствие источника сообщения уровню логирования, значимость, порядок обработки каждого уровня и другие параметры.
Типы логов
Для удобства обработки логов их делят на типы:
системные, связанные с системными событиями,
серверные, отвечающие за процесс обращения к серверу,
почтовые, работающие с отправлениями,
логи баз данных, которые отражают процессы обращения к базам данных,
авторизационные и аутентификационные, которые отвечают за процесс входа, выхода из системы, восстановление доступа и пр.
У каждого типа логов свой журнал записи. Для проверки логов авторизации нужно идти в журнал доступов, чтобы проверить загрузку системы — в журнал dmesg, за данными о запросах пользователей — в access_log. Когда одни логи пишутся отдельно от других, проще диагностировать ситуацию и найти источник проблемы.
Инструменты для работы с логами
Сбор, хранение и анализ логов вручную хороши, когда у вас один сервер. Когда серверный парк разрастается, а приложений и сервисов становится больше десяти, работу с логами целесообразно автоматизировать и использовать специальные системы логирования, например, Graylog, ELK, Loggy или Splunk. Некоторые из них позволяют организовать полномасштабный мониторинг, настроить алерт раннего обнаружения конкретной проблемы или установить пороговые значения показателей, коррелирующих с угрозами информационной безопасности.
Логи сетевого, инженерного оборудования, баз данных и приложений мы храним в облачном хранилище. И вам советуем. Даже когда у вас полно места на жестких дисках и стоит мощная защита на все случаи жизни. Оборудование рано или поздно, а чаще неожиданно, выходит из строя, а злоумышленники давно умеют чистить файлы логирования, так что логи в облаке — это возможность восстановить события и расследовать инцидент даже при полном отказе системы.
Хранение логов в облаке
Логирование кажется второстепенным процессом, который занимает время, но не дает видимых результатов. Однако это только кажется и только до тех пор, пока не появится реальная проблема, с которой можно разобраться только по логам. И только если они записаны, распределены по уровням, собираются и доступны для анализа.
Удобное логирование на бэкенде. Доклад Яндекса
Что-то всегда идет не по плану. Приходится отвечать на вопросы, «Что сломалось?», «Почему тормозит?» и «Почему мы не увидели этого раньше?». На примере простого приложения Даниил Галиев zefirior из Яндекс.Путешествий показал, как отвечать на эти вопросы и какие инструменты в этом помогут. Настроим логирование, прикрутим трассировку, разложим ошибки, и все это в удобном интерфейсе.
— Давайте начинать. Я расскажу об удобном логировании и инфраструктуре вокруг логирования, которую можно развернуть, чтобы вам с вашим приложением и его жизненным циклом было удобно жить.
Что будем делать? Мы построим небольшое приложение, наш стартап. Потом внедрим в него базовое логирование, это маленькая часть доклада, то, что поставляет Python из коробки. И дальше самая большая часть — мы разберем типичные проблемы, которые встречаются нам во время отладки, выкатки, и инструменты для их решения.
Небольшой дисклеймер: я буду говорить такие слова, как «ручка» и «локаль». Поясню. «Ручка» — возможно, яндексовый сленг, это обозначает ваши API, http или gRPC API или любые другие комбинации букв перед APU. «Локаль» — это когда я разрабатываю на ноутбуке. Вроде бы я рассказал обо всех словах, которые я не контролирую.
Приложение «Книжная лавка»
Начнем. Наш стартап — это «Книжная лавка». Главной фичей этого приложения будет продажа книг, это все, что мы хотим сделать. Дальше немного начинки. Приложение будет написано на Flask. Все сниппеты кода, все инструменты общие и абстрагированы от Python, поэтому их можно будет интегрировать в большинство ваших приложений. Но в нашем докладе это будет Flask.
Действующие лица: я, разработчик, менеджеры и мой любимый коллега Эраст. Любые совпадения случайны.
Давайте немного про структуру. Это приложение с микросервисной архитектурой. Первый сервис — Books, хранилище книг с метаданными о книгах. Он использует базу данных PostgreSQL. Второй микросервис — микросервис доставки, хранит метаданные о заказах пользователей. Cabinet — это бэкенд для кабинета. У нас нет фронтенда, в нашем докладе он не нужен. Cabinet агрегирует запросы, данные из сервиса книг и сервиса доставки.
По-быстрому покажу код ручек этих сервисов, API Books. Это ручка выгребает данные из базы, сериализует их, превращает в JSON и отдает.
Пойдем дальше. Сервис доставки. Ручка точно такая же. Выгребаем данные из базы, сериализуем их и отправляем.
И последняя ручка — ручка кабинета. В ней немного другой код. Ручка кабинета запрашивает данные из сервиса доставки и из сервиса книг, агрегирует ответы и отдает пользователю его заказы. Всё. Со структурой приложения мы по-быстрому разобрались.
Базовое логирование в приложении
Теперь давайте про базовое логирование, то, которое мы впилили. Начнем с терминологии.
Что нам дает Python? Четыре базовые, главные сущности:
— Logger, входная точка логирования в вашем коде. Вы будете пользоваться каким-то Logger, писать logging.INFO, и все. Ваш код больше ничего не будет знать о том, куда сообщение улетело и что с ним дальше произошло. За это уже отвечает сущность Handler.
— Handler обрабатывает ваше сообщение, решает, куда его отправить: в стандартный вывод, в файл или кому-нибудь на почту.
— Filter — одна из двух вспомогательных сущностей. Удаляет сообщения из лога. Другой стандартный вариант использования — это наполнение данными. Например, в вашей записи нужно добавить атрибут. Для этого тоже может помочь Filter.
— Formatter приводит ваше сообщение к нужному виду.
На этом с терминологией закончили, дальше к логированию прямо на Python, с базовыми классами, мы возвращаться не будем. Но вот пример конфигурации нашего приложения, которая раскатана на всех трех сервисах. Здесь два главных, важных для нас блока: formatters и handlers. Для formatters, есть пример, который вы можете увидеть здесь, шаблон того, как будет выводиться сообщение.
В handlers вы можете увидеть, что logging.StreamHandler использован. То есть мы выгружаем все наши логи в стандартный вывод. Всё, с этим закончили.
Проблема 1. Логи разбросаны
Переходим к проблемам. Для начала проблема первая: логи разбросаны.
Немножечко контекста. Наше приложение мы написали, конфетка уже готова. Мы можем на нем зарабатывать денежку. Мы его выкатываем в продакшен. Конечно, там не один сервер. По нашим скромным подсчетам, нашему сложнейшему приложению нужно порядка трех-четырех машинок, и так для каждого сервиса.
Теперь вопрос. Прибегает к нам менеджер и спрашивает: «Там сломалось, помоги!» Вы бежите. У вас же все логируется, это великолепно. Вы заходите на первую машинку, смотрите — там ничего нет по вашему запросу. Заходите на вторую машинку — ничего. И так далее. Это плохо, это надо как-то решать.
Давайте формализуем результат, который мы хотим увидеть. Я хочу, чтобы логи были в одном месте. Это простое требование. Немного круче то, что я хочу поиск по логам. То есть да, оно лежит в одном месте и я умею грепать, но было бы прикольно, если бы были какие-нибудь tools, крутые фичи помимо простого грепа.
И я не хочу писать. Это Эраст любит писать код. Я не про это, я сразу сделал продукт. То есть хочется меньше дополнительного кода, обойтись одним-двумя файликами, строчками, и всё.
Решение, которое можно использовать, — Elasticsearch. Давайте его попробуем поднять. Какие плюсы Elasticsearch нам даст? Это интерфейс с поиском логов. Сразу из коробки есть интерфейс, это вам не консолька, а единственное место хранения. То есть главное требование мы отработали. Нам не нужно будет ходить по серверам.
В нашем случае это будет довольно простая интеграция, и с недавним релизом у Elasticsearch выпустился новый агент, который отвечает за большинство интеграций. Они там сами впилили интеграции. Очень круто. Я составлял доклад чуть раньше и использовал filebeat, так же просто. Для логов все просто.
Немного об Elasticsearch. Не хочу рекламировать, но там много дополнительных фич. Например, крутая штука — полнотекстовый поиск по логам из коробки. Очень круто звучит. Нам пока достаточно этих плюсов. Прикручиваем.
В первую очередь нам нужно будет развернуть агент, который будет отправлять наши логи в Elasticsearch. Вы регистрируете аккаунт в Elasticsearch и дальше добавляете в ваш docker-compose. Если у вас не docker-compose, можете поднимать ручками или в вашей системе. В нашем случае добавляется вот такой блок кода, интеграции в docker-compose. Всё, сервис настроен. И вы можете увидеть в блоке volumes файл конфигурации filebeat.yml.
Вот пример filebeat.yml. Здесь настроен автоматический поиск логов контейнеров docker, которые крутятся рядом. Кастомизован выбор этих логов. По условию можно задавать, вешать на ваши контейнеры лейблы, и в зависимости от этого ваши логи будут отправляться только у определенных контейнеров. С блоком processors:add_docker_metadata все просто. В логи добавляем немножечко больше информации о ваших логах в контексте docker. Необязательно, но прикольно.
Что мы получили? Это все, что мы написали, весь код, очень круто. При этом мы получили все логи в одном месте и есть интерфейс. Мы можем поискать наши логи, вот плашечка search. Они доставляются. И можно даже в прямом эфире включить так, чтобы стрим летел к нам в логи в интерфейс, и мы это видели.
Тут я бы и сам спросил: а чего, как грепать-то? Что из себя представляет поиск по логам, что там можно сделать?
Да, из коробки в таком подходе, когда у нас текстовые логи, есть небольшой затык: мы можем по тексту задать запрос, например message:users. Это выведет нам все логи, у которых есть подстрока users. Можно пользоваться звездочками, большинством других юниксовых wild cards. Но кажется, этого недостаточно, хочется сделать сложнее, чтобы можно было нагрепать в Nginx раньше, как мы это умеем.
Давайте немного отступим от Elasticsearch и попытаемся сделать это не с Elasticsearch, а с другим подходом. Рассмотрим структурные логи. Это когда каждая ваша запись лога — это не просто текстовая строчка, а сериализованный объект с атрибутами, которые любая ваша сторонняя система может сериализовать, чтобы получить уже готовый объект.
Какие от этого есть плюсы? Это единый формат данных. Да, у объектов могут быть разные атрибуты, но любая внешняя система может прочитать именно JSON и получить какой-то объект.
Какая-никакая типизация. Это упрощает интеграцию с другими системами: не нужно писать десериализаторы. И как раз десериализаторы — это другой пункт. Вам не нужно писать в приложении прозаичные тексты. Пример: «User пришел с таким-то айдишником, с таким-то заказом». И это все нужно писать каждый раз.
Меня это напрягало. Я хочу написать: «Прилетел запрос». Дальше: «Такой-то, такой-то, такой-то», очень просто, очень по-айтишному.
Давайте дальше. Договоримся: логировать будем в формате JSON, это простой формат. Сразу Elasticsearch поддерживается, filebeat, которым мы сериализуем и попробуем впилить. Это не очень сложно. Для начала вы добавляете из библиотеки pythonjsonlogger в блок formatters JSONFormatter файлика settings, где у нас хранится конфигурация. У вас в системе это может быть другое место. И дальше в атрибуте format вы передаете, какие атрибуты вы хотите добавлять в ваш объект.
Блок ниже — это блок конфигурации, который добавляется в filebeat.yml. Здесь из коробки есть интерфейс у filebeat для парсинга JSON-логов. Очень круто. Это все. Для этогов вам больше ничего писать не придется. И теперь ваши логи похожи на объекты.
Что мы получили в Elasticsearch? В интерфейсе вы сразу видите, что ваш лог превратился в объект с отдельными атрибутами, по которым вы можете искать, создавать фильтрации и делать сложные запросы.
Давайте подведем итог. Теперь наши логи имеют структуру. По ним несложно грепать и можно писать интеллектуальные запросы. Elasticsearch знает об этой структуре, так как он распарсил все эти атрибуты. А в kibana — это интерфейс для Elasticsearch — можно фильтровать такие логи с помощью специализированного языка запросов, который предоставляет Elasticsearch.
И это проще, чем грепать. Греп имеет довольно сложный и крутой язык. Там очень много можно написать. В kibana можно сделать многие вещи проще. С этим разобрались.
Проблема 2. Тормоза
Следующая проблема — тормоза. В микросервисной архитектуре всегда и везде бывают тормоза.
Тут немного контекста, расскажу вам историю. Ко мне прибегает менеджер, главное действующее лицо нашего проекта, и говорит: «Эй-эй, кабинет тормозит! Даня, спаси, помоги!»
Мы пока ничего не знаем, лезем в Elasticsearch в наши логи. Но давайте я расскажу, что, собственно, произошло.
Эраст добавил фичу. В книгах мы теперь отображаем не айдишник автора, а его имя прямо в интерфейсе. Очень круто. Сделал он это вот таким кодом. Небольшой кусок кода, ничего сложного. Что может пойти не так?
Вы наметанным взглядом можете сказать, что с SQLAlchemy так делать нельзя, с другой ORM тоже. Нужно сделать прекэш или что-нибудь еще, чтобы в цикле не ходить в базу с маленьким подзапросиком. Неприятная проблема. Кажется, что такую ошибку вообще нельзя допустить.
Давайте расскажу. У меня был опыт: мы работали с Django, и у нас в проекте был реализован кастомный прекэш. Много лет все шло хорошо. В какой-то момент мы с Эрастом решили: давай пойдем в ногу со временем, обновим Django. Естественно, Django ничего не знает о нашем кастомном прекэше, и интерфейс поменялся. Прикэш отвалился, молча. На тестировании это не отловили. Та же самая проблема, просто ее сложнее было отловить.
Проблема в чем? Как я помогу вам решить проблему?
Давайте расскажу, что я делал до того, как начал решать именно проблему поиска тормозов.
Первое, что делаю, — иду в Elasticsearch, у нас он уже есть, помогает, не нужно бегать по серверам. Я захожу в логи, ищу логи кабинета. Нахожу долгие запросы. Воспроизвожу на ноутбуке и вижу, что тормозит не кабинет. Тормозит Books.
Бегу в логи Books, нахожу проблемные запросы — собственно, он у нас уже есть. Точно так же воспроизвожу Books на ноутбуке. Очень сложный код — ничего не понимаю. Начинаю дебажить. Тайминги довольно сложно отлавливать. Почему? Внутри SQLAlchemy довольно сложно это определить. Пишу кастомные тайм-логгеры, локализую и исправляю проблему.
Мне было больно. Сложно, неприятно. Я плакал. Хочется, чтобы этот процесс поиска проблемы был быстрее и удобнее.
Формализуем наши проблемы. Сложно по логам искать, что тормозит, потому что наш лог — это лог несвязанных событий. Приходится писать кастомные таймеры, которые показывают нам, сколько выполнялись блоки кода. Причем непонятно, как логировать тайминги внешних систем: например, ORM или библиотек requests. Надо наши таймеры внедрять внутрь либо каким-то Wrapper, но мы не узнаем, от чего оно тормозит внутри. Сложно.
Хорошее решение, которое я нашел, — Jaeger. Это имплементация протокола opentracing, то есть давайте внедрим трассировку.
Что дает Jaeger? Это удобный интерфейс с поиском запросов. Вы можете отфильтровать долгие запросы или сделать это по тегам. Наглядное представление потока запросов, очень красивая картинка, чуть позже покажу.
Тайминги логируются из коробки. С ними ничего не надо делать. Если вам нужно про какой-то кастомный блок проверить, сколько он выполняется, вы можете его обернуть в таймеры, предоставляемые Jaeger. Очень удобно.
Посмотрим, как вообще можно было найти проблему в интерфейсе и там же ее локализовать. Мы заходим в интерфейс Jaeger. Вот так выглядят наши запросы. Мы можем поискать запросы именно кабинета или другого сервиса. Сразу фильтруем долгие запросы. Нас интересуют именно долгие, их по логам довольно сложно найти. Получаем их список.
Проваливаемся в этот запрос, и видим большую портянку SQL-подзапросов. Мы прямо наглядно видим, как они исполнялись по времени, какой блок кода за что отвечал. Очень круто. Причем в контексте нашей проблемы это не весь лог. Там есть еще большая портянка на два-три слайда вниз. Мы довольно быстро локализовали проблему в Jaeger. В чем после решения проблемы нам может помочь контекст, который предоставляет Jaeger?
Jaeger логирует, например, SQL-запросы: вы можете посмотреть, какие запросы повторяются. Очень быстро и круто.
Проблему мы решили и сразу видим в Jaeger, что все хорошо. Мы проверяем по тому же запросу, что у нас теперь нет подзапросов. Почему? Предположим, мы проверим тот же запрос, узнаем тайминг — посмотрим в Elasticsearch, сколько запрос выполнялся. Тогда мы увидим время. Но это не гарантирует, что подзапросов не было. А здесь мы это видим, круто.
Давайте внедрим Jaeger. Кода нужно не очень много. Вы добавляете зависимости для opentracing, для Flask. Теперь о том, какой код мы делаем.
Первый блок кода — это настройка клиента Jaeger.
Затем мы настраиваем интеграцию с Flask, Django или с любым другим фреймворком, на который есть интеграция.
install_all_patches — самая последняя строчка кода и самая интересная. Мы патчим большинство внешних интеграция, взаимодействуя с MySQL, Postgres, библиотекой requests. Мы все это патчим и именно поэтому в интерфейсе Jaeger сразу видим все запросы с SQL и то, в какой из сервисов ходил наш искомый сервис. Очень круто. И вам не пришлось много писать. Мы просто написали install_all_patches. Магия!
Что мы получили? Теперь не нужно собирать события по логам. Как я сказал, логи — это разрозненные события. В Jaeger это одно большое событие, структуру которого вы видите. Jaeger позволяет отловить узкие места в приложении. Вы просто делаете поиск по долгим запросам, и можете проанализировать, что идет не так.
Проблема 3. Ошибки
Последняя проблема — ошибки. Да, я лукавлю. Я не помогу вам избавиться от ошибок в приложении, но я расскажу, что с ними можно делать дальше.
Контекст. Вы можете сказать: «Даня, мы логируем ошибки, у нас есть алерты на пятисотки, мы настроили. Чего ты хочешь? Логировали, логируем и будем логировать и отлаживать.
По логам вы не знаете важность ошибки. Что такое важность? Вот у вас есть одна крутая ошибка, и ошибка подключения к базе. База просто флапнула. Хочется сразу видеть, что эта ошибка не так важна, и если нет времени, не обращать на нее внимания, а фиксить более важную.
Частота появления ошибок — это контекст, который может нам помочь в ее отладке. Как отслеживать появление ошибок? Преподолжим, у нас месяц назад была ошибка, и вот она снова появилась. Хочется сразу найти решение и поправить ее или сопоставить ее появление с одним из релизов.
Вот наглядный пример. Когда я впиливал интеграцию с Jaeger, то немного поменял свою API. У меня изменился формат ответа приложения. Я получил вот такую ошибку. Но в ней непонятно, почему у меня нет ключа, lots в объекте order, и нет ничего, что мне бы помогло. Мол, смотри ошибку здесь, воспроизведи и самостоятельно отлови.
Давайте внедрим sentry. Это баг-трекер, который поможет нам в решении подобных проблем и поиске контекста ошибки. Возьмем стандартную библиотеку, поддерживаемую разработчиками sentry. В четыре строчки кода мы ее добавляем в наше приложение. Всё.
Что мы получили на выходе? Вот такой дашборд с ошибками, которые можно сгруппировать по проектам и за которыми можно следить. Огромная портянка логов с ошибками группируется в одинаковые, похожие. По ним приводится статистика. И вы также можете работать с этими ошибками с помощью интерфейса.
Посмотрим на нашем примере. Проваливаемся в ошибку KeyError. Сразу видим контекст ошибки, что было в объекте order, чего там не было. Я сразу по ошибке вижу, что мне приложение Delivery отдало новую структуру данных. Кабинет просто к этому не готов.
Что дает sentry, помимо того, что я перечислил? Формализуем.
Это хранилище ошибок, в котором можно искать их. Для этого есть удобные инструменты. Есть группировка ошибок — по проектам, по похожести. Sentry дает интеграции с разными трекерами. То есть вы можете следить за вашими ошибками, работать с ними. Вы можете просто добавлять задачу в ваш контекст, и все. Это помогает в разработке.
Статистика по ошибкам. Опять же, легко сопоставить с выкаткой релиза. В этом вам поможет sentry. Похожие события, которые произошли рядом с ошибкой, тоже могут вам помочь в поиске и понимании того, что к ней привело.
Давайте подведем итог. Мы с вами написали приложение, простое, но отвечающее потребностям. Оно помогает вам в разработке и поддержке, в его жизненном цикле. Что мы сделали? Мы собрали логи в одно хранилище. Это дало нам возможность не искать их по разным местам. Плюс у нас появился поиск по логам и сторонние фичи, наши tools.
Интегрировали трассировку. Теперь мы наглядно можем следить за потоком данных в нашем приложении.
И добавили удобный инструмент для работы с ошибками. Они в нашем приложении будут, как бы мы ни старались. Но мы будем фиксить их быстрее и качественнее.
Что еще можно добавить? Само приложение готово, оно есть по ссылке, вы можете посмотреть, как оно сделано. Там поднимаются все интеграции. Например, интеграции с Elasticsearch или трассировки. Заходите, смотрите.
Еще одна крутая штука, которую я не успел осветить, — requests_id. Почти ничем не отличается от trace_id, который используется в трассировках. Но за requests_id отвечаем мы, это самая главная его фича. Менеджер может прийти к нам сразу с requests_id, нам не потребуется его искать. Мы сразу начнем решать нашу проблему. Очень круто.
И не забывайте, что инструменты, которые мы внедряли, имеют overhead. Это проблемы, которые нужно рассматривать для каждого приложения. Нельзя бездумно внедрить все наши интеграции, облегчить себе жизнь, а потом думать, что делать с тормозящим приложением.
Проверяйте. Если на вас это не сказывается, круто. Вы получили только плюсы и не решаете проблемы с тормозами. Не забывайте об этом. Всем спасибо, что слушали.