Велосипедостроение или логирование своими руками в проекте на C++

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

Требования к логгеру

1. Возможность потокобезопасной записи.
2. Максимальная скорость записи.
3. Запись в файл/вывод на экран.
4. Наличие одного экземпляра класса в программе.
5. Легкость.
6. Расширяемость функционала.

Реализация требований

Всем известно, что как лодку назовешь, так она и поплывет, поэтому мы наше детище назовем Победа, то есть RapidLogger. Да да, скромностью я никогда не отличался…

1. Потокобезопасную запись будем реализовывать при помощи объектов синхронизации потоков, а именно мьютексов. Так как мой проект на Qt, то и воспользуемся QMutex и QMutexLocker.
QMutexLocker — это класс, в конструкторе которого осуществляется попытка захвата мьютекса (то есть вызов конструктора может надолго заблокировать вызывающую функцию), а в деструкторе — его свобождение. Поместив в начало метода write разрабатываемого логгера автоматическую переменную QMutexLocker locker(&m_mutex), где m_mutex — поле типа QMutex класса логгера, изящно делаем ее потокобезопасной. То есть имеем следующее:

//rapidlogger.h
class RapidLogger
{
public:
    void write(const char *cLogData, uint32 nDataSize);
private:
    QMutex m_mutex;
};

//rapidlogger.cpp
void RapidLogger::write(const char *cLogData, uint32 nDataSize)
{
    QMutexLocker locker(&m_mutex);
    /*TODO: ... */
}

Естественно, можно использовать любую другую реализацию мьютексов.

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

Добавим в класс RapidLogger поле char *m_tempBuf и метод bool RapidLogger::flush(). Теперь каждый раз при записи в лог, данные будут попадать сначала в буфер m_tempBuf, память под который будет выделена при инициализации объекта. В случае, если буфер начинает переполняться, происходит автоматический вызов функции flush, сбрасывающей содержимое буфера на диск/экран и очищающий его. На этом шаге имеем следующее:

//rapidlogger.h
class RapidLogger
{
public:
    bool flush();
    void write(const char *cLogData, uint32 nDataSize);
private:
    char *m_tempBuf;
    uint32 m_tempBufSize;
    uint32 m_tempBufInUseSize;
    QMutex m_mutex;
};

//rapidlogger.cpp
bool RapidLogger::flush()
{
    if (m_tempBufInUseSize)    
        if (fwrite(m_tempBuf, sizeof(char), m_tempBufInUseSize, m_logStream) != m_tempBufInUseSize)
            return false;

    m_tempBufInUseSize = 0;
    return (EOF != fflush(m_logStream));
}

void RapidLogger::write(const char *cLogData, uint32 nDataSize)
{
    QMutexLocker locker(&m_mutex);
    if (m_tempBufSize {
        //Ветка 1. Вся очередная запись помещается в буфер
        if (nDataSize+m_tempBufInUseSize <= m_tempBufSize) {
            memcpy(m_tempBuf+m_tempBufInUseSize, cLogData, nDataSize);
            m_tempBufInUseSize += nDataSize;
        }
        //Ветка 2. Только часть очередной записи помещается в буфер
        else {
            //Записываем сколько помещается
            uint32 nFirsPartSize = m_tempBufSize-m_tempBufInUseSize;
            memcpy(m_tempBuf+m_tempBufInUseSize, cLogData, nFirsPartSize);
            m_tempBufInUseSize += nFirsPartSize;
            //Сбрасываем буфер на диск
            if (!flush())
                throw STREAM_IO_EXC;
            //Записываем оставшуюся часть очередной записи в буфер
            uint32 nSecondPartSize = nDataSize-nFirsPartSize;
            memcpy(m_tempBuf+m_tempBufInUseSize, cLogData+nFirsPartSize, nSecondPartSize);
            m_tempBufInUseSize += nSecondPartSize;
        }
    }
    else {
        if (nDataSize != fwrite(cLogData, sizeof(char), nDataSize, m_logStream) || !flush())
            throw STREAM_IO_EXC;
        return;
    }

    //Сброс буфер на диск, если он заполнен боллее чем на 90%
    if (m_tempBufInUseSize > m_tempBufSize*0.9) {
        if (!flush())
            throw STREAM_IO_EXC;
    }
}

3. Самое время поговорить о том, как и куда нам писать информацию. Как видно из кода выше, во время записи и сброса мы пользуемся функциями CRT fwrite и fflush, как наиболее быстрыми и универсальными. Для вывода информации на экран (в стандартный поток вывода) эти функции нам также подходят. Добавим метод changeStream, выполняющий смену потока вывода. По умолчанию в конструкторе поток установлен stdout. Метода changeStream также задает размер временного буфера. Причем в случае нулевого последующая запись будет осуществляться непосредственно в поток.

void RapidLogger::changeStream(std::string sFileName, uint32 nTmpBufSize) {
    flush();
    m_logStream = fopen(sFileName.c_str(), "w");
    if (!m_logStream)
        throw STREAM_IO_EXC;

    if (0 != nTmpBufSize)
        m_tempBuf = new char[nTmpBufSize];
    else
        m_tempBuf = NULL;
    m_tempBufSize = nTmpBufSize;
    m_tempBufInUseSize = 0;
}

4. Так как файл лога требуется один, а желающих писать в него потоков в программе много, то следует сделать так, чтобы был только единственный экземпляр класса логгера и множество ссылок на него. Воспользуемся паттерном Одиночка (singleton).
В результате получим следующий код (конечный вариант):

//rapidlogger.h
#ifndef RAPIDLOGGER_H
#define RAPIDLOGGER_H

#include "defenitions.h"
#include "ilogger.h"
#include <QMutex>
#include <stdio.h>

class RapidLogger : public ILogger
{
public:
    static RapidLogger *instance();
    void freeInstance();
    void changeStream(std::string sFileName, uint32 nTmpBufSize);
    bool flush();
    void write(const char *cLogData, uint32 nDataSize);
    static uint32 getRefsCount();
protected:
    ~RapidLogger();
private:
    RapidLogger();

    static RapidLogger *m_instance;
    static uint32 m_nRefConter;
    FILE *m_logStream;
    char *m_tempBuf;
    uint32 m_tempBufSize;
    uint32 m_tempBufInUseSize;
    QMutex m_mutex;
};

#endif // RAPIDLOGGER_H

//rapidlogger.cpp
#include "exceptions.h"
#include "rapidlogger.h"
#include <memory.h>

RapidLogger *RapidLogger::m_instance = NULL;
uint32 RapidLogger::m_nRefConter = 0;

RapidLogger::RapidLogger()
{
    m_logStream = stdout;
    m_tempBuf = NULL;
    m_tempBufSize = 0;
    m_tempBufInUseSize = 0;
}

RapidLogger::~RapidLogger()
{
    flush();
    if (m_logStream != stdout)
        fclose(m_logStream);
    delete [] m_tempBuf;
}

RapidLogger *RapidLogger::instance()
{
    m_nRefConter++;
    if (!m_instance)
        m_instance = new RapidLogger;
    return m_instance;
}

void RapidLogger::freeInstance()
{
    if (!m_nRefConter)
        return;

    m_nRefConter--;
    if (!m_nRefConter) {
        delete this;
        m_instance = NULL;
    }
}

void RapidLogger::changeStream(
    std::string sFileName, uint32 nTmpBufSize)
{/*...*/}

bool RapidLogger::flush()
{/*...*/}

void RapidLogger::write(const char *cLogData, uint32 nDataSize)
{/*...*/}

uint32 RapidLogger::getRefsCount()
{
    return m_nRefConter;
}

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

5. и 6. Минимум кода и максимум свободы для бурной фантазии. Несмотря, что синхронизация реализована с использованием средств библиотеки Qt, остальной функционал класса содержит исключительно функции стандартной библиотеки C++. В качестве расширения, например, можно переопределить оператор <<.

Тестирование

Запуск на 10 потоках, каждый из которых делал по 5000 записей строки длиной 100 символов при логгировании в файл на диске показал 15 кратное превосходство в скорости в случае использования временного буфера, что и требовалось доказать. При этом чуть более, чем полностью все строки лога оказались целостными.

P.S. Ваши предложения по ускорению принимаются в комментариях. Плюс буду очень рад, если найдется доброволец и сравнит быстродействие RapidLogger`а с коробочными решениями. У самого к сожалению времени на это пока не хватило.