Logging. Лучшие практики
От: Буравчик Россия  
Дата: 22.09.18 16:41
Оценка: 2 (1) +1
Поделитесь полезными советами про логи.

Что пишут умные люди:


1. Писать в лог чем больше, тем лучше.

Больше данных — легче разобраться с проблемами.

НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.


2. Использовать машиночитаемый формат сообщений (json)

Рекомендация вроде ясна, удобно в дальнейшем анализировать.
Вот только куда ни посмотришь на логи, везде обычная строка, без key-value или json


3. Рекомендуют записывать контекст.

Просто сообщение "был такой то exception" не катит, т.к. не понятно с каким пользователем/действием/запросом это было связано.
Нужно записывать запрос к серверу, имя пользователя, id сессии и т.п.

НО...! В процессе выполнения "главной задачи" (обработки запроса/транзакции) обычно задача разделяется на меньшие задачи (формирует запросы к базе, выполняется дополнительная обработка данных и т.п.). Эти меньшие задачи тоже нужно отслеживать (логгировать). К ним дописывать тот же контекст, т.е. дублировать/протаскивать контекст в сообщениях? С другой стороны, если вообще не указывать контекст, то как связать эту внутреннюю подзадачу с "главным" запросом при разборе проблем.


4. Держать все логи рядом (вместе)

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


5. Собирать метрики

Например, времени выполнения запросов, процент отказов и т.п.
НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.



Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?
Best regards, Буравчик
Re: Logging. Лучшие практики
От: bnk СССР http://unmanagedvisio.com/
Дата: 22.09.18 17:10
Оценка: 72 (3)
Здравствуйте, Буравчик, Вы писали:

Б>Поделитесь полезными советами про логи


Б>1. Писать в лог чем больше, тем лучше.

Б>Больше данных — легче разобраться с проблемами.
Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.

вообще много логов не будет, потому что программистам их лень писать.
Просто следить чтобы в цикле всякую хрень в лог не фигачило. Что обязательго логгировать,
так это все внешние вызовы (входящие и исходящие) и все эксепшены.
Еще есть уровни логгирования.

Б>2. Использовать машиночитаемый формат сообщений (json)


Бред, imho
Важно чтобы лог можно было отфильтровать (по времени допустим, или там по юзеру)
json вообще не уперся, если обычный текст фильтруется (каждая строчка содержит таймстемп и юзера)

Б>3. Рекомендуют записывать контекст.


Б>Просто сообщение "был такой то exception" не катит, т.к. не понятно с каким пользователем/действием/запросом это было связано.

Б>Нужно записывать запрос к серверу, имя пользователя, id сессии и т.п.

Б>НО...! В процессе выполнения "главной задачи" (обработки запроса/транзакции) обычно задача разделяется на меньшие задачи (формирует запросы к базе, выполняется дополнительная обработка данных и т.п.). Эти меньшие задачи тоже нужно отслеживать (логгировать). К ним дописывать тот же контекст, т.е. дублировать/протаскивать контекст в сообщениях? С другой стороны, если вообще не указывать контекст, то как связать эту внутреннюю подзадачу с "главным" запросом при разборе проблем.


Да, вообще это проблема. Пусть не контекст, так хотя бы время, с максимальной точностью.
Для http есть глобальный контекст вызова (входящего). Он так или иначе доступен.
Нафига это вообще надо — если несколько вызовов обрабатываются параллельно и пишут в один лог,
Чтобы можно было разобраться что к чему относится.

Б>4. Держать все логи рядом (вместе)

Б>Это понятно. Но иногда выделяют отдельные лог файлы для ошибок, например. Также удобно собирать логи с нескольких машин где-то на удаленном сервере.

Пофик

Б>5. Собирать метрики


Б>Например, времени выполнения запросов, процент отказов и т.п.

Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.

Б>Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?


Как на практике. Недавно запустили AppDynamics (https://www.appdynamics.com)

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

Можно отследить грохнувшуюся операцию от того чтов приложени х юзер нажал на кнопку y, до момента когда потом упала хранимка в какой-то базе, вызванная через 5 промежуточных сервисов (половина rest, половина wcf). Показывает стеки вызовов, как внутри приложения, так и между приложениями, для баз — выполняемый sql. Также все тайминги операций и изменения в них.

В общем для мониторинга — пока выглядит довольно неплохо.
Отредактировано 22.09.2018 17:39 bnk . Предыдущая версия . Еще …
Отредактировано 22.09.2018 17:30 bnk . Предыдущая версия .
Отредактировано 22.09.2018 17:23 bnk . Предыдущая версия .
Re: Logging. Лучшие практики
От: A13x США  
Дата: 22.09.18 19:55
Оценка: 10 (3)
Здравствуйте, Буравчик, Вы писали:

Б>Поделитесь полезными советами про логи.


Б>Что пишут умные люди:



Б>1. Писать в лог чем больше, тем лучше.


Б>Больше данных — легче разобраться с проблемами.


Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.


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

Б>2. Использовать машиночитаемый формат сообщений (json)


Б>Рекомендация вроде ясна, удобно в дальнейшем анализировать.

Б>Вот только куда ни посмотришь на логи, везде обычная строка, без key-value или json

Это у вас так. Одно время я поработал в МС на написании сервисов и в моем отделе как раз был принят такой подход со структурированным логгингом. Это на порядок улучшало работу с логами — можно было строить довольно сложные запросы вида "сколько запросов с таким и таким параметром привело к ошибке такого типа.

Б>3. Рекомендуют записывать контекст.


Б>Просто сообщение "был такой то exception" не катит, т.к. не понятно с каким пользователем/действием/запросом это было связано.

Б>Нужно записывать запрос к серверу, имя пользователя, id сессии и т.п.

Б>НО...! В процессе выполнения "главной задачи" (обработки запроса/транзакции) обычно задача разделяется на меньшие задачи (формирует запросы к базе, выполняется дополнительная обработка данных и т.п.). Эти меньшие задачи тоже нужно отслеживать (логгировать). К ним дописывать тот же контекст, т.е. дублировать/протаскивать контекст в сообщениях? С другой стороны, если вообще не указывать контекст, то как связать эту внутреннюю подзадачу с "главным" запросом при разборе проблем.


Нужен глобальный ID ассоциированный с запросом пользователя и локальные ID ассоциированые с запросами к зависимостям. Этого достаточно.
Эти две вещи можно объединить например так.

Б>4. Держать все логи рядом (вместе)


Б>Это понятно. Но иногда выделяют отдельные лог файлы для ошибок, например. Также удобно собирать логи с нескольких машин где-то на удаленном сервере.


Не вижу большого смысла. Информационные сообщения могут быть настолько же важны.

Б>5. Собирать метрики


Б>Например, времени выполнения запросов, процент отказов и т.п.

Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.

Можно совместить с логами, это работает наиболее эффективно.

Б>Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?
Re: Logging. Лучшие практики
От: scf  
Дата: 22.09.18 20:56
Оценка: 24 (5) +2 :)
Здравствуйте, Буравчик, Вы писали:

Б>Поделитесь полезными советами про логи.


Тема очень интересная, но почему-то никто о ней не говорит и книжек "как правильно делать логгирование и что такое ELK" я не видел. Даже подумываю статью на тему запилить.
Вкратце о типах логов, как я их понимаю:

— аудит. Это структурированные логи, содержащие как минимум название операции, параметры операции и результат операции. Большинство, или даже все, поля аудит лога стандартизированы. Эти логи обычно выгружаются в отчетную систему и используются для аналитики типа "какие фичи нашего приложения самые популярные" и "кто удалил данные"

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

— метрики. Агрегированные, обычно с окном в одну минуту, численные показатели работы приложения. Самые популярные — кол-во запросов в секунду, кол-во ошибок в секунду, объем свободной памяти и т.п. Нужны для изучения поведения приложения на проде и для расследования сбоев. Бессмысленны, если нет софта для построения графиков по метрикам.

— трассировка. id вызывающей стороны, тип операции, время выполнения операции. Очень важны для изучения быстродействия в распределенных системах. Пример: https://github.com/openzipkin/zipkin . В рабоче-крестьянском софте часто достаточно добавлять время выполнения запроса в аудит лог.

— текстовые логи.

Попробую покомментировать по пунктам:

Б>1. Писать в лог чем больше, тем лучше.

Б>Больше данных — легче разобраться с проблемами.
Больше данных — хорошая мысль, НО — если у вас 1 тыс запросов в секунду, это сколько мегабайт в час на диск получается? Еще есть соображение персональных или секурных данных — они не должны попадать в лог. Уровень логгирования в продакшне — дело сугубо индивидуальное, но нужно стремиться иметь хотя бы логи аудита

Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.

А что там хочется найти? Наверное, ошибки, которые нужно расследовать? И логи, которые относятся к запросу, вызвавшему ошибку? Это решается культурой разработки(писать в ERROR только важные ошибки) и наличием RequestId в логах.

Б>2. Использовать машиночитаемый формат сообщений (json)

Б>Рекомендация вроде ясна, удобно в дальнейшем анализировать.
Б>Вот только куда ни посмотришь на логи, везде обычная строка, без key-value или json
Здесь важен баланс — текстовые логи сложно парсить, json-логи нечитаемы без сооответствующего софта.

Б>3. Рекомендуют записывать контекст.

Б>Просто сообщение "был такой то exception" не катит, т.к. не понятно с каким пользователем/действием/запросом это было связано.
Б>Нужно записывать запрос к серверу, имя пользователя, id сессии и т.п.

Б>НО...! В процессе выполнения "главной задачи" (обработки запроса/транзакции) обычно задача разделяется на меньшие задачи (формирует запросы к базе, выполняется дополнительная обработка данных и т.п.). Эти меньшие задачи тоже нужно отслеживать (логгировать). К ним дописывать тот же контекст, т.е. дублировать/протаскивать контекст в сообщениях? С другой стороны, если вообще не указывать контекст, то как связать эту внутреннюю подзадачу с "главным" запросом при разборе проблем.

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

Б>4. Держать все логи рядом (вместе)

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

Б>5. Собирать метрики

Б>Например, времени выполнения запросов, процент отказов и т.п.
Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.
Есть готовые библиотеки для метрик, которые умеют собирать стандартные метрики и агрегировать пользовательские в мин/макс/среднее/персентили

Б>Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?

Важно понимать, какием образом логи потом будут использоваться, и логгировать так, чтобы упростить последующее чтение логов. Разделять программные ошибки (NPE) с клиентскими (валидаторы) и админскими (недоступна база). Использовать requestId, чтобы найти запрос по ошибке и ошибку по запросу.
Хорошо помогает использование собственной обертки для логгирования c методами типа logValidationFailed/logUnexpectedError/logRemoteError/итп с запретом логгировать напрямую через логгер.
Re: Logging. Лучшие практики
От: Kernan Ниоткуда https://rsdn.ru/forum/flame.politics/
Дата: 24.09.18 14:34
Оценка: 10 (2)
Здравствуйте, Буравчик, Вы писали:

Б>Поделитесь полезными советами про логи.

Нужно собирать такую информацию которая позволить воспроизводить проблемы на стенде.

Б>Что пишут умные люди:

Б>1. Писать в лог чем больше, тем лучше.
На одном проекте писались все входы и выходы из функция + дополнительные логи. В какой-то момент придумали сделать циклический буфер и во время проблемы дампить только его чтобы не нагружать систему. Этим продумктом был софтсвитч .
Б>Больше данных — легче разобраться с проблемами.
Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.
Если знать куда глдяеть, то всё находится.
Б>2. Использовать машиночитаемый формат сообщений (json)
Как по мне, так для машиночитаемого формата тебе нужно будет потом написать тулзу которая это всё бдует машиночитать.
Б>3. Рекомендуют записывать контекст.
Да.
Б>4. Держать все логи рядом (вместе)
Б>Это понятно. Но иногда выделяют отдельные лог файлы для ошибок, например. Также удобно собирать логи с нескольких машин где-то на удаленном сервере.
Не обязательно, но нужен способ получить их все в одно место для обработки 1-2 командами.
Б>5. Собирать метрики
Метрики это || штука. Их надо собирать всегда по многим параметрам чтобы потом понимать и разные юзкейзы использования системы, и вести статистику, и смотреть какие, сколько и где были проблемы.
Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.
Да. Можно сделать микросервис который будет именно что получать метрики из разных точек управления и отправлять на сервера.
Б>Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?
Много логов с разным уровнем, всякие дебаг-фишки вроде снятия сетевого дампа и т.п, метрики тоже есть вроде падений, перезагрузок, рост памяти и т.п., в общем, всё стандартно.
Sic luceat lux!
Re: Logging. Лучшие практики
От: MadHuman Россия  
Дата: 24.09.18 15:44
Оценка: 15 (4)
Здравствуйте, Буравчик, Вы писали:

Б>1. Писать в лог чем больше, тем лучше.

Б>Больше данных — легче разобраться с проблемами.
Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.
Как сложилось у нас.
Руководствоваться полезностью логов для решения проблем. Не общей мыслью, что чем больше тем полезнее. А смотрим на конкретную часто (или потенциально критичную хоть и не часто) возникающую проблему и думаем что стоит писать. Постепенно, с таким подходом для всех значимых кэйсов добавите логи с нужной инфой.


Б>2. Использовать машиночитаемый формат сообщений (json)

Б>Рекомендация вроде ясна, удобно в дальнейшем анализировать.
Б>Вот только куда ни посмотришь на логи, везде обычная строка, без key-value или json
структура у лога будет в любом случае (кроме простейших), хотя бы минимально: дата-время, уровень, подсистема, тип события, сообщение, +набор произвольных параметров.
и в более менее серьёзно используемом продукте логов будет не мало, глазами там искать будет неудобно — однозначно понадобятся фильтрации/выборки по параметрам логов, а это значит что лучше машиночитаемый.
Вариантов тулов масса. Можете в бд писать, можете в csv. ДЛя csv логов, есть отличная тулса — LogParser


Б>3. Рекомендуют записывать контекст.

тут уже были рекомендации, можно записывать некий ид-запроса (контекста), а в начале (при его создании) трэйс — с подробной инфой о нём.
если практика покажет, что удобно что-то дублировать — добавите.


Б>4. Держать все логи рядом (вместе)

Б>Это понятно. Но иногда выделяют отдельные лог файлы для ошибок, например.
если у вас будет тулса для просмотра с фильтрациями/выборками — то удобнее вместе.


Б>5. Собирать метрики

Б>Например, времени выполнения запросов, процент отказов и т.п.
Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.
метрики это по сути инфо-логи, если есть точки когда что-то сняли (время обработки всего реквеста, какого-то действия, запроса к БД и тп) — логируйте как инфо-лог.
Re[2]: Logging. Лучшие практики
От: Sinclair Россия https://github.com/evilguest/
Дата: 02.10.18 16:36
Оценка:
Здравствуйте, scf, Вы писали:

scf>Здравствуйте, Буравчик, Вы писали:


Б>>Поделитесь полезными советами про логи.


scf>Тема очень интересная, но почему-то никто о ней не говорит и книжек "как правильно делать логгирование и что такое ELK" я не видел. Даже подумываю статью на тему запилить.

scf>Вкратце о типах логов, как я их понимаю:

scf>- аудит. Это структурированные логи, содержащие как минимум название операции, параметры операции и результат операции. Большинство, или даже все, поля аудит лога стандартизированы. Эти логи обычно выгружаются в отчетную систему и используются для аналитики типа "какие фичи нашего приложения самые популярные" и "кто удалил данные"

Уточнение: аудит обычно содержит данные о взаимодействии с нашей системой снаружи. В классике — это лог действий пользователя. То есть прямо вот одно действие — одна строка.
Если там под капотом происхолит стопятьсот действий — их в этот лог не пишем: аудит хранится для того, чтобы понять, кто виноват. И очень важно логгировать user identity.
Уйдемте отсюда, Румата! У вас слишком богатые погреба.
Re: Logging. Лучшие практики
От: bzig  
Дата: 06.10.18 20:39
Оценка:
Б>3. Рекомендуют записывать контекст.

Контекст удобно инициализировать при начале обработки запроса, хранить в thread-local переменной и чистить при завершении. Тогда никуда ничего протаскивать не надо, всё доступно всем подзадачам. Более того, все java-logging фрэймворки умеют с таким контекстом работать и автоматически дописывать его к сообщениям, т.е. подзадачам даже и знать про него не надо. Ещё нужно не забывать пробрасывать его в другие потоки, если задача в пул передаётся или в очередь.
Re: Logging. Лучшие практики
От: yenik  
Дата: 16.10.18 08:06
Оценка:
Б>1. Писать в лог чем больше, тем лучше.

Б>Больше данных — легче разобраться с проблемами.


Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.


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


Б>2. Использовать машиночитаемый формат сообщений (json)


Б>Рекомендация вроде ясна, удобно в дальнейшем анализировать.

Б>Вот только куда ни посмотришь на логи, везде обычная строка, без key-value или json

Ага, вот IdentityServer4, который, казалось бы, рекомендуется лучшими собаководами.
  Лог
[16:25:31.31 Information] IdentityServer4.Hosting.IdentityServerMiddleware
Invoking IdentityServer endpoint: IdentityServer4.Endpoints.AuthorizeEndpoint for /connect/authorize

[16:25:31.31 Information] IdentityServer4.Endpoints.AuthorizeEndpoint
ValidatedAuthorizeRequest
{
"ClientId": "my.client",
"ClientName": "My Client",
"RedirectUri": "http://localhost:46688/MyClient.html",
"AllowedRedirectUris": [
"http://localhost:46688/MyClient.html"
],
"SubjectId": "anonymous",
"ResponseType": "code",
"ResponseMode": "query",
"GrantType": "authorization_code",
"RequestedScopes": "offline_access openid",
"State": "1234qwe",
"LoginHint": "test-reset-pswd@qa.qa",
"Raw": {
"response_type": "code",
"client_id": "my.client",
"scope": "offline_access openid",
"redirect_uri": "http://localhost:46688/MyClient.html",
"state": "1234qwe",
"login_hint": "test-reset-pswd@qa.qa"
}
}

[16:25:31.31 Information] IdentityServer4.ResponseHandling.AuthorizeInteractionResponseGenerator
Showing login: User is not authenticated

Не знаю, как и назвать.

Б>3. Рекомендуют записывать контекст.

Да, глобальный контекст запроса.

Б>5. Собирать метрики

Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.

Использовать готовые решения. Например, писать в Prometheus и анализировать в Grafana.
Re: Logging. Лучшие практики
От: AleksandrN Россия  
Дата: 18.10.18 15:04
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Поделитесь полезными советами про логи.


Б>Что пишут умные люди:



Б>1. Писать в лог чем больше, тем лучше.


Б>Больше данных — легче разобраться с проблемами.


Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.


Сделать разные уровни логирования. В коде при выводе в лог указывать минимальный уровень, при котором выводится сообщение. Сообщения об ошибках писать всегда. Тогда при тестировании и отладке можно будет включить очень подробное логирование, а при эксплуатации — менее подробный уровень логирования. Это особенно актуально для систем, работающих 24/7 с высокой нагрузкой, т.к. очень подробное логирование может сильно нагружать диски и быть узким местом в производительности системы в целом.

Б>2. Использовать машиночитаемый формат сообщений (json)


Б>Рекомендация вроде ясна, удобно в дальнейшем анализировать.

Б>Вот только куда ни посмотришь на логи, везде обычная строка, без key-value или json

Обычно логи люди читают. Машиночитаемый формат удобен для автоматизации анализа логов, но нужна ещё будет утилита, что бы людям смотреть было удобнее.

Б>3. Рекомендуют записывать контекст.


Б>Просто сообщение "был такой то exception" не катит, т.к. не понятно с каким пользователем/действием/запросом это было связано.

Б>Нужно записывать запрос к серверу, имя пользователя, id сессии и т.п.

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

Б>4. Держать все логи рядом (вместе)


Б>Это понятно. Но иногда выделяют отдельные лог файлы для ошибок, например. Также удобно собирать логи с нескольких машин где-то на удаленном сервере.


Ещё ротацию логов сделать.

Б>5. Собирать метрики


Б>Например, времени выполнения запросов, процент отказов и т.п.

Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.

Писать время с точностью до микро- или наносекунд и писать код возврата. Затем сделать автоматический анализатор для подсчёта времени обработки одного подключения и процента отказов.
Re[2]: Logging. Лучшие практики
От: white_znake  
Дата: 19.10.18 09:55
Оценка:
Здравствуйте, bnk, Вы писали:


Б>>2. Использовать машиночитаемый формат сообщений (json)


bnk>Бред, imho

bnk>Важно чтобы лог можно было отфильтровать (по времени допустим, или там по юзеру)
bnk>json вообще не уперся, если обычный текст фильтруется (каждая строчка содержит таймстемп и юзера)

Имеется в виду, что сейчас для поиска по логам используют ElastiSearch а у него любовь в JSON.

Тут проблема не логировать, а искать в логах. Когда у тебя несколько сотен пользовательей за сутки — это одно (проблемы писка нет).
А если у тебя сотни миллионов пользователей, то проблемы в поиске логов — есть.
Re: Logging. Лучшие практики
От: white_znake  
Дата: 19.10.18 10:02
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Поделитесь полезными советами про логи.


Б>Что пишут умные люди:



Б>1. Писать в лог чем больше, тем лучше.

Б>Больше данных — легче разобраться с проблемами.
Несколько уровней логирования. Структурированные логи (JSON), поиск через elastisearch.

Б>НО...! Ведь если на каждый чих писать в лог, потом в этих логах ничего не найти.



Б>2. Использовать машиночитаемый формат сообщений (json)


Б>Рекомендация вроде ясна, удобно в дальнейшем анализировать.

Б>Вот только куда ни посмотришь на логи, везде обычная строка, без key-value или json
Смотри ответ на пунтк №1.

Б>3. Рекомендуют записывать контекст.

Б>Просто сообщение "был такой то exception" не катит, т.к. не понятно с каким пользователем/действием/запросом это было связано.
Б>Нужно записывать запрос к серверу, имя пользователя, id сессии и т.п.
Без этого ни как. HttpContext, Сессия и пр. — нужно логировать, без контекста — нет лога.

Б>НО...! В процессе выполнения "главной задачи" (обработки запроса/транзакции) обычно задача разделяется на меньшие задачи (формирует запросы к базе, выполняется дополнительная обработка данных и т.п.). Эти меньшие задачи тоже нужно отслеживать (логгировать). К ним дописывать тот же контекст, т.е. дублировать/протаскивать контекст в сообщениях? С другой стороны, если вообще не указывать контекст, то как связать эту внутреннюю подзадачу с "главным" запросом при разборе проблем.

Контекст + уровни логирования.

Б>4. Держать все логи рядом (вместе)

Б>Это понятно. Но иногда выделяют отдельные лог файлы для ошибок, например. Также удобно собирать логи с нескольких машин где-то на удаленном сервере.
В микросервисной архитектуре у тебя могут быть как локальные логи, а потом собирать агрегировать логи, так и централизованный лог. Это на твой вкус.

Б>5. Собирать метрики

Б>Например, времени выполнения запросов, процент отказов и т.п.
Б>НО.... Чтобы такое делать надо вообще отдельную подсистему писать — для расчета этих метрик. Как это на практике, непонятно.
Тут уже до фига всего автоматизировано: ApplicationInsight and etc.
Re: JSON логи
От: Буравчик Россия  
Дата: 25.10.18 21:07
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?


Копаю в сторону JSON. Обнаружил утилиту jq — очень удобно работать с jsonlines (удобный отбор, преобразования)

Подумалось еще вот что:

Добавление данных в каждое сообщение лога

Возможно удобно иметь конструкцию, которая бы позволяла добавлять в каждое сообщение некоторую информацию (например, request_id)

with log.context(request_id='...') as inner_log:
    # здесь во все JSON-лог сообщения будет добавляться предопределенный ключ request_id
    inner_log.info()
    inner_log.debug()


Сообщений в логе в зависимости от exception

Также интересна возможность запись в лог дополнительные сообщения только при условии необработанного exception, сокращая debug-сообщений на production.

При обычной работе попадут только info сообщения и выше, а если произойдет исключение, то добавятся еще и debug сообщения автоматически, чтобы упростить отладку


with log.context() as inner_log:
  try:
    inner_log.info()
    # это сообщение попадет в лог, только если будет брошен exception
    inner_log.debug() 
  except:
    inner_log.dump_debug() # указание логгеру вывести debug сообщения


По-моему оба пункта отсутствуют в стандартных логгерах.
В каких библиотеках логгирования реализовано ли что-то подобное? (Язык не важен)
Best regards, Буравчик
Re[2]: JSON логи
От: bzig  
Дата: 26.10.18 00:58
Оценка: 4 (1)
Здравствуйте, Буравчик, Вы писали:

Б>Здравствуйте, Буравчик, Вы писали:


Б>>Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?


Б>Копаю в сторону JSON. Обнаружил утилиту jq — очень удобно работать с jsonlines (удобный отбор, преобразования)


Б>Подумалось еще вот что:


Б>Добавление данных в каждое сообщение лога


Более того, все java-logging фрэймворки умеют с таким контекстом работать и автоматически дописывать его к сообщениям, т.е. подзадачам даже и знать про него не надо. Ещё нужно не забывать пробрасывать его в другие потоки, если задача в пул передаётся или в очередь.


Б>Сообщений в логе в зависимости от exception


Прикольная фича, но есть два непонятных момента

— когда очистятся запомненные дебаги, если исключение не случилось?
— в каком порядке попадут в лог info(), debug(), info(), exception ? Дебаг после обоих инфо? Или он всё в памяти кэширует? А если всё кэшируется до поры до времени, то будет нарушен порядок сообщений из двух разных потоков?
Re[3]: JSON логи
От: Буравчик Россия  
Дата: 26.10.18 06:45
Оценка:
Здравствуйте, bzig, Вы писали:

Б>>Добавление данных в каждое сообщение лога


B>Более того, все java-logging фрэймворки умеют с таким контекстом работать и автоматически дописывать его к сообщениям, т.е. подзадачам даже и знать про него не надо. Ещё нужно не забывать пробрасывать его в другие потоки, если задача в пул передаётся или в очередь.

B>

Спасибо, нашел. Похоже, в java это называется Mapped Diagnostic Context. Посмотрю.

Б>>Сообщений в логе в зависимости от exception


B>Прикольная фича, но есть два непонятных момента


B>- когда очистятся запомненные дебаги, если исключение не случилось?


Очистятся при выходе из блока (при завершении контекста).

B>- в каком порядке попадут в лог info(), debug(), info(), exception ? Дебаг после обоих инфо? Или он всё в памяти кэширует? А если всё кэшируется до поры до времени, то будет нарушен порядок сообщений из двух разных потоков?


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

Можно все сообщения кэшировать, а записывать только в конце. Этот вариант удобен, что сообщения "не путаются", но длительность контекста может очень большой — вплоть до срока запуска приложения (от старта до завершения). Тогда вообще никаких логов не будет. Но на "коротких" дистанциях (обработка одного запроса, одна транзакция) этот метод был бы, наверное, предпочтительнее.

В общем, думаю, что будет лучше, если будет выбор.
Best regards, Буравчик
Re[4]: JSON логи
От: bzig  
Дата: 26.10.18 13:12
Оценка:
B>>- в каком порядке попадут в лог info(), debug(), info(), exception ? Дебаг после обоих инфо? Или он всё в памяти кэширует? А если всё кэшируется до поры до времени, то будет нарушен порядок сообщений из двух разных потоков?

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


Самому по файлу глазами восстанавливать может быть долго, а "| sort" медленно. Получается, надо какие-то агрегаторы использовать, вроде Splunk.

Б>Можно все сообщения кэшировать, а записывать только в конце. Этот вариант удобен, что сообщения "не путаются", но длительность контекста может очень большой — вплоть до срока запуска приложения (от старта до завершения). Тогда вообще никаких логов не будет. Но на "коротких" дистанциях (обработка одного запроса, одна транзакция) этот метод был бы, наверное, предпочтительнее.


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

Б>В общем, думаю, что будет лучше, если будет выбор.


Конкретно в Яве я про такое не слышал, но написать свой наследник от логера, кэшировать дебаги и сбрасывать в лог, если пришлось писать сообщение об ошибке — довольно простая задача. До сих пор ни кем не решана думаю как раз и из-за "перепутывания". Лог ведь может писаться по дням или даже по часам или с ограничением по размеру — так что отложенные записи могут попасть совсем не в тот файл, что был бы при своевременной записи.
Re[5]: JSON логи
От: bzig  
Дата: 26.10.18 13:24
Оценка:
B>Конкретно в Яве я про такое не слышал, но написать свой наследник от логера, кэшировать дебаги и сбрасывать в лог, если пришлось писать сообщение об ошибке — довольно простая задача. До сих пор ни кем не решана думаю как раз и из-за "перепутывания". Лог ведь может писаться по дням или даже по часам или с ограничением по размеру — так что отложенные записи могут попасть совсем не в тот файл, что был бы при своевременной записи.

Хотя вру, непростая. Все распространённые явовские логеры время ставят при записи в файл, а не при передаче сообщения логеру, так что или отказываться от стандартной фичи простановки времени и делать всё самому или время будет неправильное.

Что можно было бы сделать — кэшировать дебаги, если логеру пришлось писать ошибку, но присвоить ей какой-нибудь номер на лету и дописать время к дебагам и сбросить в отдельный файл с этим номером. А для этих отдельных файлов иметь свой Layout, который не ставит время, так что у дебагов будет правильное время, но файл будет отдельный.
Re[5]: JSON логи
От: Буравчик Россия  
Дата: 26.10.18 13:29
Оценка:
Здравствуйте, bzig, Вы писали:

B>Самому по файлу глазами восстанавливать может быть долго, а "| sort" медленно. Получается, надо какие-то агрегаторы использовать, вроде Splunk.


jq умеет сортировать по ключу. Вполне можно обойтись им в консоли.

B>Конкретно в Яве я про такое не слышал, но написать свой наследник от логера, кэшировать дебаги и сбрасывать в лог, если пришлось писать сообщение об ошибке — довольно простая задача. До сих пор ни кем не решана думаю как раз и из-за "перепутывания".


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

B>Лог ведь может писаться по дням или даже по часам или с ограничением по размеру — так что отложенные записи могут попасть совсем не в тот файл, что был бы при своевременной записи.


Да, действительно, не учитывал таких проблем, спасибо.

Для себе решил сделать, как и говорил, два варианта:
— Синхронноый, когда дебаг сообщения будут добавляться вперемешку с инфо сообщениями. Будет использоваться на коротких промежутках (секунды)
— Отложенный, когда дебаг сообщения будут добавляться после инфо сообщений. Будет использоваться на длинных промежутках (минуты и часты).

Попробую, что получится.

Еще мысль. Можно debug сообщения писать в отдельный файл. Если exception не было, то файл стирать. Если был — переносить дебаг сообщения в основной лог.
Но, думаю, на prod сервере это будет не очень хорошо с точки зрения производительности (ввиду большого количества дебаг сообщений). Собственно, по этой причине дебаг и отключают.
Best regards, Буравчик
Re[6]: JSON логи
От: bzig  
Дата: 26.10.18 13:38
Оценка:
Б>Еще мысль. Можно debug сообщения писать в отдельный файл. Если exception не было, то файл стирать. Если был — переносить дебаг сообщения в основной лог.
Б>Но, думаю, на prod сервере это будет не очень хорошо с точки зрения производительности (ввиду большого количества дебаг сообщений). Собственно, по этой причине дебаг и отключают.

Ага, только что написал об этом в отдельном сообщении
Re: Logging. Лучшие практики
От: VladiCh  
Дата: 06.02.19 08:29
Оценка:
Здравствуйте, Буравчик, Вы писали:

Б>Поделитесь полезными советами про логи.


Б>Как ЭТО происходит у вас? Поделитесь своими практиками/правилами?


Использовать индексацию/анализ логов. Можно коммерческий продукта типа Splunk, можно ELK stack и т п
Писать контекстно-специфичные вещи в лог
Писать только то что необходимо. Запись хранение и индексация логов вещи не бесплатные
Использовать простой формат для логов (никакого json). json увеличивает в разы стоимость их обработки.
Подождите ...
Wait...
Пока на собственное сообщение не было ответов, его можно удалить.