К написанию данной статьи меня сподвиг опыт работы с проектами в которых либо отсутсвоала система логирования как таковая, либо присутствовало ее жалкое подобие, по которому было невозможно ни определить проблему, ни даже примерное место ее появления. Под катом немного теории и непосредственно практическая реализация класса для записи логов на С++.
Мне часто приходилось сталкиваться с полным отсутствием понимания назначения логирования в приложениях, хотя система логирования это далеко не второстепенная фаза в разработке проекта. Но, зачастую, люди это понимают уже на стадии сдачи поекта, когда введение полноценной системы логирования — процесс достаточно затратный и как результат, оставляют все как есть. Что в результате имеем? А имеем мы систему, в которой любая проблема у заказчика превращается в головную боль разработчика, т.к невозможно восстановить причины возникновения проблемы у заказчика, т.е у разработчика есть только описание проблемы от человека, у которого эта проблема воспроизвелась. К сожалению, мы живем не в идеальном мире и как правило описания проблемы носит малоинформативный характер, т.к пользователи системы не являются грамотными тестерами и не могут описать проблему подробно(есть конечно приятные исключения, но их мало). Особенно остро проблема логирования стоит когда нет возможности воспроизведения проблемы на своей стороне.
Я бы хотел выделить основные ошибки логирования с которыми я сталкивался:
Ниже перечислены лишь несколько плюсов, которые сразу приходят в голову:
Хорошо расписанное назначение логов, а также советы по построению системы логирования расписаны здесь.
Я предлагаю свою реализацию класса, который может применятся для записи логов, реализация вдохновлена статьей ссылку на котрую я дал выше.
Основные настройки которые могут быть выполнены по отношению к классу:
Класс реализован с использованием библиотеки boost и является кроссплатформенным за исключением ф-ии Timestamp() которая является windows-зависимой. Ф-ия легко переписывается под любую другую ОС, при необходимости.
Logger.h
Logger.cpp
Пример создания удобного интерфейса к классу:
Надеюсь этим постом я сподвигну людей не использующих логи, на их использование и надеюсь моя реализацию будет им полезна. Удачной всем отладки :)
Вступление
Мне часто приходилось сталкиваться с полным отсутствием понимания назначения логирования в приложениях, хотя система логирования это далеко не второстепенная фаза в разработке проекта. Но, зачастую, люди это понимают уже на стадии сдачи поекта, когда введение полноценной системы логирования — процесс достаточно затратный и как результат, оставляют все как есть. Что в результате имеем? А имеем мы систему, в которой любая проблема у заказчика превращается в головную боль разработчика, т.к невозможно восстановить причины возникновения проблемы у заказчика, т.е у разработчика есть только описание проблемы от человека, у которого эта проблема воспроизвелась. К сожалению, мы живем не в идеальном мире и как правило описания проблемы носит малоинформативный характер, т.к пользователи системы не являются грамотными тестерами и не могут описать проблему подробно(есть конечно приятные исключения, но их мало). Особенно остро проблема логирования стоит когда нет возможности воспроизведения проблемы на своей стороне.
Типичные ошибки
Я бы хотел выделить основные ошибки логирования с которыми я сталкивался:
- Интерфейс к логам является набором #define'ов под которыми скрывается простой fprintf в файл. А что если появится новый поток? Или понадобится более умная обработка логов? Правильно все сломается и придется переписывать.
- Строчка выводимая в лог является конкантенацией имени подсистемы и непосредственно сообщения. Например в модуле ответсвенном за взаимодействие с БД, строчка типа: «sql: <SQL_QUERY_TEXT>». О чем говорит эта строчка? Да ни чем, просто о факте, что где-то был выполнен запрос к БД.
- Нет timestamp при выводе строки лога.
- Нет порогового разделения логов, т.е нет возможности отключить часть логов или выключить их совсем(сомнительная опция :) )
- Слишком редкая запись информации в лог(например в начале и в конце ф-ии, без трассировки ее)
- Малоинформативные записи(не выводится значения переменных и т.д)
Зачем нужны логи?
Ниже перечислены лишь несколько плюсов, которые сразу приходят в голову:
- Возможность быстрого определения причин проблемы, без многочасового сидения в дебагере, пытаясь определить проблему.
- Возможность «удаленной отладки», т.е возможность отлаживать приложение по имеющимся логам от заказчика(очень полезно когда нет возможности тестировать свое приложение без участия заказчика)
- Перекладывания части работы на техническую поддержку. Т.е support обучается типовым проблемам, секциям в логах и т.д. После чего они сами в состоянии будут определить лежащие на поверхности проблемы, не отвлекая каждый раз разработчиков по пустякам.
Хорошо расписанное назначение логов, а также советы по построению системы логирования расписаны здесь.
Я предлагаю свою реализацию класса, который может применятся для записи логов, реализация вдохновлена статьей ссылку на котрую я дал выше.
Основные настройки которые могут быть выполнены по отношению к классу:
- Выбор имени лог файла
- Выбор директории где будут храниться лог файлы
- Включение\выключение межпроцессорной синхронизации
- Ограничение размера лог файла
- Ограничение числа лог файлов, которые могут быть сохранены в директории
- Задание процедуры, котрая будет вызвана при ошибке в записи в лог файл, или при его открытии
- Задание процедуры, которая будет изменять каждую строчку при записи, так, как необходимо пользователю. Удобно, когда Вы не хотите, чтобы кто-то посторонний читал Ваш лог.
- Уровень логов, которые в данный момент могут быть выведены(всего в классе представлен 3 уровня: Обычный, Расширеный и Дебажный). Т.е отсекает все логи приоритет которых выше порога.
Класс реализован с использованием библиотеки boost и является кроссплатформенным за исключением ф-ии Timestamp() которая является windows-зависимой. Ф-ия легко переписывается под любую другую ОС, при необходимости.
Реализация:
Logger.h
#ifndef _LOGGER_
#define _LOGGER_
#include <string>
#include <fstream>
#include <sstream>
#include <boost/interprocess/sync/named_mutex.hpp>
#include <boost/scoped_ptr.hpp>
#include <boost/filesystem/path.hpp>
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{eNormal, eExtended, eDebug};
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_
* This source code was highlighted with Source Code Highlighter.Logger.cpp
#include "Logger.h"
#include <ctime>
#include <boost/filesystem/operations.hpp>
#include <boost/interprocess/sync/scoped_lock.hpp>
#include <set>
#include <algorithm>
#include <windows.h>
namespace fs = boost::filesystem;
namespace multiprocess = boost::interprocess;
using namespace smart_log;
Logger::Logger(const LogParameters& xParameters):
m_xParameters(xParameters),
m_xMutex(multiprocess::open_or_create,
(xParameters.m_strLogFileName + std::string("smart_logger_mutex") ).c_str() ),
m_uiCurrentLogSize(0)
{
m_xMutex.unlock();
m_xOfstream.exceptions(std::ofstream::failbit | std::ofstream::badbit);
m_xFullFileName = m_xParameters.m_xLogSavedPath;
m_xFullFileName /= xParameters.m_strLogFileName;
}
void Logger::WriteLog(LogLevel xLevel, const std::string& strMessage)
try
{
multiprocess::scoped_lock<boost::interprocess::named_mutex> xLock;
if(m_xParameters.m_bIsMultiThreaded)
{
xLock = multiprocess::scoped_lock<multiprocess::named_mutex>(m_xMutex, multiprocess::defer_lock_type());
xLock.lock();
}
CreatePath(m_xParameters.m_xLogSavedPath);
//Don't do anything if the current log level less then the message demands
if(xLevel > m_xParameters.m_xLogLevel)
return;
if(m_uiCurrentLogSize + strMessage.length() > m_xParameters.m_uiLogMaxSize)
HandleLogSizeExcess();
if( !m_xOfstream.is_open() )
m_xOfstream.open( (m_xFullFileName.file_string() + "-" + Timestamp() + ".log").c_str() );
//Make an output string
std::ostringstream xStream;
xStream << "[" << Timestamp() << "]: " << strMessage;
const std::string& xFinalString = xStream.str();
if(m_xParameters.m_pObfuscater)
m_xOfstream << m_xParameters.m_pObfuscater(xFinalString) << std::endl;
else
m_xOfstream << xFinalString << std::endl;
m_uiCurrentLogSize += strMessage.length();
}
catch (std::ofstream::failure xFail)
{
if(m_xParameters.m_pErrorHandler)
m_xParameters.m_pErrorHandler("Problem with a file creation or writing to the already existing file.");
else
throw;
}
void Logger::HandleLogSizeExcess()
{
if(m_xOfstream.is_open())
m_xOfstream.close();
//Goes through the log directory and finds files which looks like "m_strLogFileName-*Timestamp*"
fs::directory_iterator xEndIterator;
std::set<std::string> xFileList;
for( fs::directory_iterator it(m_xParameters.m_xLogSavedPath); it != xEndIterator; ++it )
{
std::string xCurrentFile = it->path().filename();
if( fs::is_regular_file(it->status()) )
if(xCurrentFile.find(m_xParameters.m_strLogFileName) != std::string::npos)
xFileList.insert(xCurrentFile);
}
//If the log files number exceeds the m_siMaxSavedLogs then keep on removing
//files until current files number won't be less then threshold
if(m_xParameters.m_siMaxSavedLogs)
{
if(xFileList.size() >= m_xParameters.m_siMaxSavedLogs)
{
for(std::set<std::string>::iterator it = xFileList.begin(); it != xFileList.end()
&& xFileList.size() >= m_xParameters.m_siMaxSavedLogs;)
{
fs::remove(fs::path(m_xParameters.m_xLogSavedPath) /= *it);
xFileList.erase(it++);
}
}
}
else//Save files property is turned off hence remove all existing log files
{
for(std::set<std::string>::iterator it = xFileList.begin(); it != xFileList.end();)
{
fs::remove(fs::path(m_xParameters.m_xLogSavedPath) /= *it);
xFileList.erase(it++);
}
}
m_uiCurrentLogSize = 0;
//Create a new file
m_xOfstream.open( (m_xFullFileName.file_string() + "-" + Timestamp() + ".log").c_str() );
}
void Logger::CreatePath(fs::path xPath)
try
{
//If a directory doesn't exist then try to create full path up to the required directory
if( !fs::exists(m_xParameters.m_xLogSavedPath) )
{
fs::path xTmpPath;
for(fs::path::iterator xIt = m_xParameters.m_xLogSavedPath.begin();
xIt != m_xParameters.m_xLogSavedPath.end();
++xIt)
{
xTmpPath /= *xIt;
if( !fs::exists(xTmpPath) )
fs::create_directory(xTmpPath);
}
}
}
catch (fs::basic_filesystem_error<fs::path>)
{
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 << xTime.wDay << "."
<< xTime.wMonth << "."
<< xTime.wYear << "-"
<< xTime.wHour << "."
<< xTime.wMinute << "."
<< xTime.wSecond << "."
<< xTime.wMilliseconds;
return xStream.str();
}
* This source code was highlighted with Source Code Highlighter.Пример создания удобного интерфейса к классу:
#include "Logger.h"
#include <boost/scoped_ptr.hpp>
#include <sstream>
#include <iostream>
class LogInstance
{
static boost::scoped_ptr<smart_log::Logger> m_spLogger;
public:
static const boost::scoped_ptr<smart_log::Logger>& 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 << __FILE__ << ": "<< __LINE__ << " " << __FUNCTION__ << "(): " << MSG;\
LogInstance::GetLog()->WriteNormalLog(xStrm);\
}
#define EXTENDED_LOG(MSG)\
{\
std::ostringstream xStrm;\
xStrm << __FILE__ << ": "<< __LINE__ << " " << __FUNCTION__ << "(): " << MSG;\
LogInstance::GetLog()->WriteExtendedLog(xStrm);\
}
#define DEBUG_LOG(MSG)\
{\
std::ostringstream xStrm;\
xStrm << __FILE__ << ": "<< __LINE__ << " " << __FUNCTION__ << "(): " << MSG;\
LogInstance::GetLog()->WriteDebugLog(xStrm);\
}
* This source code was highlighted with Source Code Highlighter.Надеюсь этим постом я сподвигну людей не использующих логи, на их использование и надеюсь моя реализацию будет им полезна. Удачной всем отладки :)
