Что такое лог у программистов

Что такое логирование?

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

Сложность реальных приложений

Возьмем для примера типичный сайт. Что он в себя включает?

И это только самый простой случай. Реальность же значительно сложнее: множество разноплановых серверов, системы кеширования (ускорения доступа), асинхронный код, очереди, внешние сервисы, облачные сервисы. Все это выглядит как многослойный пирог, внутри которого где-то работает нами написанный код. И этот код составляет лишь небольшую часть всего происходящего. Как в такой ситуации понять, на каком этапе был сбой, или все пошло не по плану? Для этого, как минимум, нужно определить, в каком слое произошла ошибка. Но даже это не самое сложное. Об ошибках в работающем приложении узнают не сразу, а уже потом, — когда ошибка случилась и, иногда, больше не воспроизводится.

Логирование

И для всего этого многообразия систем существует единое решение — логирование. В простейшем случае логирование сводится к файлу на диске, куда разные программы записывают (логируют) свои действия во время работы. Такой файл называют логом или журналом. Как правило, внутри лога одна строчка соответствует одному действию.

Выше небольшой кусок лога веб-сервера Хекслета. Из него видно ip-адрес, с которого выполнялся запрос на страницу и какие ресурсы загружались, метод HTTP, ответ бекенда (кода) и размер тела ответа в HTTP. Очень важно наличие даты. Благодаря ей всегда можно найти лог за конкретный период, например на то время, когда возникла ошибка. Для этого логи грепают:

Когда программисты только начинают свой путь, они, часто не зная причину ошибки, опускают руки и говорят «я не знаю, что случилось, и что делать». Опытный же разработчик всегда первым делом говорит «а что в логах?». Анализировать логи — один из базовых навыков в разработке. В любой непонятной ситуации нужно смотреть логи. Логи пишут все программы без исключения, но делают это по-разному и в разные места. Чтобы точно узнать, куда и как, нужно идти в документацию конкретной программы и читать соответствующий раздел документации. Вот несколько примеров:

Многие программы логируют прямо в консоль, например Webpack показывает процесс и результаты сборки:

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

Уровни логирования

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

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

Во-вторых, во время запуска программы указывается уровень логирования, необходимый в конкретной ситуации. По умолчанию используется уровень info, который используется для описания каких-то ключевых и важных вещей. При таком уровне будут выводиться и warning, и error. Если поставить уровень error, то будут выводиться только ошибки. А если debug, то мы получим лог, максимально наполненный данными. Обычно debug приводит к многократному росту выводимой информации.

Уровни логирования, обычно, выставляются через переменную окружения во время запуска программы. Например, так:

Существует и другой подход, основанный не на уровнях, а на пространствах имен. Этот подход получил широкое распространение в JS-среде, и является там основным. Фактически, он построен вокруг одной единственной библиотеки debug для логирования, которой пронизаны практически все JavaScript-библиотеки как на фронтенде, так и на бекенде.

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

Запуск с нужным пространством:

Ротация логов

Со временем количество логов становится большим, и с ними нужно что-то делать. Для этого используется ротация логов. Иногда за это отвечает сама программа, но чаще — внешнее приложение, задачей которого является чистка. Эта программа по необходимости разбивает логи на более мелкие файлы, сжимает, перемещает и, если нужно, удаляет. Подобная система встроена в любую операционную систему для работы с логами самой системы и внешних программ, которые могут встраиваться в нее.

С веб-сайтами все еще сложнее. Даже на небольших проектах используется несколько серверов, на каждом из которых свои логи. А в крупных проектах тысячи серверов. Для управления такими системы созданы специализированные программы, которые следят за логами на всех машинах, скачивают их, складывают в заточенные под логи базы данных и предоставляют удобный способ поиска по ним.

Здесь тоже есть несколько путей. Можно воспользоваться готовыми решениями, такими как DataDog Logging, либо устанавливать и настраивать все самостоятельно через, например, ELK Stack

Источник

Что такое лог (log) программы.

Решая различные компьютерные задачи, можно не раз столкнуться с таким понятием как лог (с англ. log). Лог какой-то программы. Давайте попробуем разобраться что это такое и для чего это нужно.

Log (с англ. журнал). У большинства программ, которые установлены на вашем компьютере, есть этот самый журнал.

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

Зачем же программе вести какие-то записи, какой-то журнал?

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

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

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

В каждой записи содержится информация о том, что происходило с программой и когда это происходило.

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

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

Источник

Как правильно писать логи (?)

Тема может и банальная, но когда программа начинает работать как то не так, и вообще вести себя очень странно, часто приходится читать логи. И много логов, особенно если нет возможности отлаживать программу и не получается воспроизвести ошибку. Наверно каждый выработал для себя какие то правила, что, как и когда логировать. Ниже я хочу рассмотреть несколько правил записи сообщений в лог, а также будет небольшое сравнение библиотек логирования для языков php, ruby и go. Сборщики логов и системы доставки не будут рассматриваться сознательно (их обсуждали уже много раз).

Есть такая linux утилита, а также по совместительству сетевой протокол под названием syslog. И есть целый набор RFC посвящённый syslog, один из них описывает уровни логирования https://en.wikipedia.org/wiki/Syslog#Severity_level (https://tools.ietf.org/html/rfc5424). Согласно rfc 5424 для syslog определено 8 уровней логирования, для которых также дается краткое описание. Данные уровни логирования были переняты многими популярными логерами для разных языков программирования. Например, http://www.php-fig.org/psr/psr-3/ определяет те же самые 8 уровней логирования, а стандартный Ruby logger использует немного сокращённый набор из 5 уровней. Несмотря на формальное указание в каких случаях должен быть использован тот или иной уровень логов, зачастую используется комбинация вроде debug/info/fatal — первый для логирования во время разработки и тестирования, второй и третий в расчёте на продакшен. Потом в какой то момент на продакшене начинает происходить что то не понятное и вдруг оказывается, что info логов не хватает — бежим включать debug. И если они не сильно нагружают систему, то зачастую так и остаются включенными в продакшен окружении. По факту остаётся два сценария, когда нужно иметь логи:

В языке Go в котором всё упрощено до предела, стандартный логер тоже прилично покромсали и оставили следующие варианты:

Я часто при написании программы с нуля повсеместно использую debug уровень для логирования с расчётом, что на продакшене будет выставлен уровень логирования info и тем самым сократится зашумлённость сообщениями. Но в таком подходе часто возникают ситуация, что логов вдруг становится не хватать. Трудно угадать, какая информация понадобиться, что бы отловить редкий баг. Возможно рационально всегда использовать по умолчанию уровень info, а в обработчиках ошибок уровень error и выше. Но если у вас сотни и больше сообщений лога в секунду, то тогда наверно есть смысл тонкой настройки между info/debug. В таких ситуациях уже имеет смысл использовать специализированные решения что бы не просаживать производительность.

Есть ещё тонкий момент, когда вы пишите что то вроде logger.debug(entity.values) — то при выставленном уровне логирования выше debug содержимое entity.values не попадёт в лог, но оно каждый раз будет вычисляться отъедая ресурсы. В Ruby логеру можно передать вместо строки сообщения блок кода: Logger.debug < entity.values >. В таком случае вычисления будут происходить только при выставленном соответствующем уровне лога. В языке Go для реализации ленивого вычисления в логер можно передать объект поддерживающий интерфейс Stringer.

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

Типичный формат строки сообщения в логе можно условно разделить на следующие составные части:

Но с единым контекстом в рамках запроса возникает проблема с различными ORM, http клиентами или другими сервисами\библиотеками, которые живут своей жизнью. И ещё хорошо, если они предоставляют возможность переопределить свой стандартный логер хотя бы глобально, а вот выставить контекст для логера в рамках запроса зачастую не реально. Данная проблема в основном актуальна для многопоточной обработки, когда один процесс обслуживает множество запросов. Но например в фрэймворке Rails имеется очень тесная интеграция между всеми компонентами и запросы ActiveRecord могут писаться в лог вместе с глобальным контекстом для текущего сетевого запроса. А в языке Go некоторые библиотеки логирования позволяют динамически создавать новый объект логера с нужным контекстом, выглядит это примерно так:

После этого такой экземпляр логера можно передать как зависимость в другие объекты. Но отсутствие стандартизированного интерфейса логирования (например как psr-3 в php) провоцирует создателей библиотек хардкодить малосовместимые реализации логеров. Поэтому если вы пишите свою библиотеку на Go и в ней есть компонент логирования, не забудьте предусмотреть интерфейс для замены логера на пользовательский.

Источник

Логирование как способ отлаживать код

Почему так важно запретить самому себе отладку руками?

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

Поэтому вам надо будет несколько раз запускать этот код в отладочном режиме, проводя часы отладки над одним и тем же куском кода. И это только вы один столько времени потратили над этой частью программы. Каждый член команды, кому «посчастливится» работать с этим кодом, будет вынужден прожить ту же самую историю, которую прожили вы.

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

Проблематика: Сложно отлаживать составной код

Возможный алгоритм решения проблемы:

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

Давайте посмотрим пример. Вы знаете, что по отдельности все реализации интерфейсов работают (т.к. написаны тесты, доказывающие это). Но при взаимодействии всего вместе возникает некорректное поведение. Что вам нужно? Нужно логировать ответы от «корректных» интерфейсов:

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

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

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

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

Источник

Необходимо ли логирование программ?

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

Реализация:

#include string >
#include
#include
#include
#include
#include

namespace smart_log
<
typedef void (*ErrorHandler)( const std:: string &);
typedef const std:: string (*Obfuscater)( const std:: string &);
//This type provides constant which set the writing log mode.
//If a current mode is bigger then methods mode the writing will be ignored.
//It needs for log flood control
enum LogLevel;

struct LogParameters
<
std:: string m_strLogFileName;
//Pointer to a function which does appropriate manipulations in case of a log corruption. Set to 0 if it doesn’t need.
ErrorHandler m_pErrorHandler;
//Pointer to a function which obfuscates each string writing to a log file. Set to 0 if it doesn’t need.
Obfuscater m_pObfuscater;
size_t m_uiLogMaxSize;
unsigned short m_siMaxSavedLogs;
//Is the thread synchronization needed?
bool m_bIsMultiThreaded;
//Indicates whether log will be saved or not. If this flag is set then log will be saved when its size exceed m_uiLogMaxSize.
//Use m_siMaxSavedLogs to control how many log files will be saved. If the current number of log files has reached the m_siMaxSavedLogs then
//new saved log would replace the oldest one.
bool m_bIsSaveLog;
LogLevel m_xLogLevel;
//Path to the log location. It will be created if no exists.
boost::filesystem::path m_xLogSavedPath;
>;

class Logger
<
//—————————————Data
size_t m_uiCurrentLogSize;
short int m_siCurrentSavedLogs;
LogParameters m_xParameters;
std::ofstream m_xOfstream;
boost::interprocess::named_mutex m_xMutex;
//File name with full path in which it will be create
boost::filesystem::path m_xFullFileName;
//—————————————Internal methods
private :
//Common method for message writing
void WriteLog(LogLevel xLevel, const std:: string & strMessage);
void HandleLogSizeExcess();
std:: string Timestamp();
void CreatePath(boost::filesystem::path xPath);
//—————————————Interface
public :
Logger( const LogParameters& xParameters);

//Set of methods which concretize the common WriteLog method to log levels.
void WriteNormalLog( const std::ostringstream& strMessage)
<
WriteLog( eNormal, strMessage.str() );
>
void WriteExtendedLog( const std::ostringstream& strMessage)
<
WriteLog( eExtended, strMessage.str() );
>
void WriteDebugLog( const std::ostringstream& strMessage)
<
WriteLog( eDebug, strMessage.str() );
>
//————————————Setters
void SetErrorHandler(ErrorHandler pErrorHandler)
<
m_xParameters.m_pErrorHandler = pErrorHandler;
>
void SetLogMode(LogLevel xLevel)
<
m_xParameters.m_xLogLevel = xLevel;
>
>;
>
#endif _LOGGER_

namespace fs = boost::filesystem;
namespace multiprocess = boost::interprocess;
using namespace smart_log;

void Logger::WriteLog(LogLevel xLevel, const std:: string & strMessage)
try
<
multiprocess::scoped_lock xLock;
if (m_xParameters.m_bIsMultiThreaded)
<
xLock = multiprocess::scoped_lock (m_xMutex, multiprocess::defer_lock_type());
xLock. lock ();
>
CreatePath(m_xParameters.m_xLogSavedPath);

>
catch (fs::basic_filesystem_error )
<
if (m_xParameters.m_pErrorHandler)
m_xParameters.m_pErrorHandler( «Problem with a directory creation» );
else
throw ;
>

std:: string Logger::Timestamp()
<
SYSTEMTIME xTime;
::GetSystemTime(&xTime);
std::ostringstream xStream;
xStream «.»
«.»
«-»
«.»
«.»
«.»
return xStream.str();
>

Пример создания удобного интерфейса к классу:

class LogInstance
<
static boost::scoped_ptr m_spLogger;
public :
static const boost::scoped_ptr & GetLog()
<
if (!m_spLogger)
<
smart_log::LogParameters xParams;
xParams.m_bIsMultiThreaded = true ;
xParams.m_pErrorHandler = 0;
xParams.m_pObfuscater = 0;
xParams.m_siMaxSavedLogs = 0;
xParams.m_strLogFileName = «log_file» ;
xParams.m_uiLogMaxSize = 8192;
xParams.m_xLogLevel = smart_log::eNormal;
xParams.m_xLogSavedPath = «./log/log/log» ;
m_spLogger.reset( new smart_log::Logger(xParams));
>
return m_spLogger;
>

#define NORMAL_LOG(MSG)\
<\
std::ostringstream xStrm;\
xStrm «: » » » «(): » WriteNormalLog(xStrm);\
>
#define EXTENDED_LOG(MSG)\
<\
std::ostringstream xStrm;\
xStrm «: » » » «(): » WriteExtendedLog(xStrm);\
>
#define DEBUG_LOG(MSG)\
<\
std::ostringstream xStrm;\
xStrm «: » » » «(): » WriteDebugLog(xStrm);\
>

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

Источник