Реализуем полезный лог на основе потоков

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

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

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

Вторая причина гораздо более прозаична. Невнимание к мелочам. Особенно в начале проекта. И чем моложе команда, тем эффект катастрофичнее. Конечно, гораздо интереснее обсуждать перспективы использования мультиметодов [1], чем следить за тем, чтобы операторы отделялись пробелами. Да и к конечной функциональности подобные мелочи особого отношения не имеют. Не лучше ли сначала сконцентрироваться на первоочередных требованиях, ведь время проекта и бюджет ограничены…

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

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

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

• Полный интерфейс
• Кроссплатформенность
• Вывод сообщений в консоль IDE
• Удобство и простота использования
• Средства привлечения внимания разработчика

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

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

Кроссплатформенность. Подсистема журналирования должна изначально поддерживать все используемые платформы. Это особенно важно, когда нет возможности полноценно и постоянно тестировать работу приложения на всех операционных системах. То, что прекрасно работало на iOS, может странно себя вести на Android-устройстве и наоборот. Конечно, система вывода сообщений не заменяет автоматические тесты. Но они достаточно сложны, внедрение и поддержка требует значительных трудозатрат и, нравственно это или нет, часто о тестах благополучно забывают. Поэтому я считаю, что лучше начинать с полноценно работающего минимума, чем ничего не делать, мечтая об идеале. Хотя в любом случае в идеале должны быть и тесты и удобная подсистема ведения лога.

Вывод сообщений в консоль IDE. Обратите внимание, в список базовых требований не вынесено “Вывод сообщений в постоянное хранилище (файл или базу данных)”. Хотя обычно это как раз то, чего многие ждут от лога. В файле журнала появляется необходимость, когда хоть как-то работающая система отдается на тестирования будущим пользователям или специальному отделу. Но на начальных этапах гораздо полезнее ставить в известность о проблемах программистов, чем тестировщиков.

Потому что пользовательский интерфейс может сильно опаздывать за функциональностью – все это время разработчики будут “вариться в собственном соку”. Есть большая разница, увидел ты проблему спустя несколько секунд или недель после того, как ее сотворил.

Удобство и простота использования. Программист существо ленивое. Предположим, нужно сообщить о проблеме: получено изображение размером 100 на 120, в то время как текущие настройки приложения устанавливают ограничение на минимальный размер 128 на 128. Если реализована возможность вывода только простой строки, от разработчика для составления адекватного вывода потребуется

1. Привести четыре числа к строковому типу
2. Из полученных частей составить строку
3. Передать строку в лог

Даже если язык предоставляет средства вывода в форматированную строку (например, sprintf [2] и stringstream [3]) потребуется создавать различные промежуточные переменные, терять время, размывать основную логику… В общем не стоит удивляться, если в результате в лог будет выведено что-то типа “недопустимый размер изображения”. Смысл слова “недопустимый”, такой понятный сейчас, через пару недель будет утерян практически полностью. В результате дизайнер, вместо того, чтобы исправить проблемную картинку, вынужден будет обращаться к программисту за разъяснениями.

Поэтому подсистема ведения журнала должна предоставлять средства удобного форматирования выводимых строк, не заставляя разработчика вручную приводить к строковым хотя бы базовые типы. Здесь в C++ возможны два направления.

Первое – наследие из C. Форматирование строки по шаблону. Т.е. функция вывода в лог должна обладать интерфейсом и функциональностью, аналогичной sprintf. Это дело вкуса, лично мне этот вариант глубоко несимпатичен. В первую очередь отталкивает необходимость работы с переменным числом разнотипных параметров функции. Т.е. возможность проверки входных данных практически никакая. Кроме того, хоть и упрощенная, но необходимость ручного приведения типов присутствует. Например, нужно помнить, что для вывода беззнакового числа следует применять код форматирования %u вместо %i – совсем не хочется вспоминать подобное, когда голова занята решением другой задачи. Плюс возможны неуловимые на этапе компиляции проблемы, когда не совпадает количество (порядок, тип) кодов форматирования и фактически переданных параметров.

Второй вариант – потоки вывода. Всех недостатков предыдущего решения он лишен: нет зависимости параметров, если передан объект, не поддерживающий оператора вывода – будет ошибка компиляции, а не всевозможные сюрпризы, не нужно вручную выделять буферы, приводить типы и т.п. И главное – вывод строки сообщения с включением переменных разных типов можно реально записать в одну строку. Да и с реализацией особых сложностей не предвидится – стандартная библиотека уже содержит поток stringstream [3], что наводит на мысль о наличии готовых алгоритмов потокового вывода в строку.

Средства привлечения внимания разработчика. Программист занят. Он может не заметить ошибку даже в консоли вывода IDE. Проблема может легко потеряться среди тучи информационных сообщений. Поэтому, во-первых, лог должен поддерживать настройку уровня вывода. Например, “выводить только ошибки и предупреждения”. Это нужно, но этого мало – настройку требуется время от времени выполнять. А программист занят.

Здесь приходит на выручку специальный макрос assert [4]. Он позволяет прервать выполнение программы на проблемном месте. Результат получается разный – Visual Studio дает возможность продолжить выполнения после вывода окна и пугающего звука, XCode звуками не пугает, но и продолжить выполнение не разрешает. В общем, внимание гарантировано. При этом само диагностическое сообщение окажется на момент прерывания в конце консоли вывода IDE, часто полностью избавляя от необходимости просматривать стек вызова в поисках причины остановки.

Рисунок 1. Прерывание работы программы на предупреждении

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

Для начала рассмотрим базовый интерфейс класса журналирования

class Log
{
public:

Первым делом вводим четыре уровня подробности лога (в порядке объявления):

1. Полное отключение лога
2. Вывод только ошибок
3. Вывод предупреждений и ошибок
4. Вывод всех видов сообщений

    enum DebugLevel
    {
        DEBUG_LEVEL_DISABLED = 0,
        DEBUG_LEVEL_ERROR = 1,
        DEBUG_LEVEL_WARNING = 2,
        DEBUG_LEVEL_MESSAGE = 3,
    };

Соответственно добавим еще три идентификатора допустимых видов сообщений: информационное сообщение, предупреждение и ошибка.

    enum MessageType
    {
    	MESSAGE_INFO,
    	MESSAGE_WARNING,
    	MESSAGE_ERROR,
    };

Следующий метод предназначен для создания экземпляра класса. Прямое создание запрещаем, поместив конструктор в защищенную (protected) область.

static void createInstance();

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

    void setDebugLevel(DebugLevel level);    
protected:

Защищенную область открывает обещанный закрытый конструктор.

    Log();

Единственный чисто виртуальный метод предназначен для зависящего от платформы вывода информации в консоль IDE

	virtual void writeIDEDebugString(const std::string& message, MessageType type) = 0;
    
private:

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

    void writeMessage(const std::string& message);
    void writeWarning(const std::string& message);
    void writeError(const std::string& message);

Метод вывода в файл. Здесь его реализация приведена не будет, так как прямого отношения к теме статьи он не имеет.

    void appendToFile(const std::string& message);

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

	void writeMessage(const std::string& message, MessageType type);

Из данных класса нам понадобится хранить уровень подробности лога и его экземпляр.

    DebugLevel mDebugLevel;
    static Log* sInstance;
};

Рассмотрим реализацию некоторых методов
Функции вывода сообщений однотипны, потому ограничимся рассмотрением исходного кода сообщения об ошибке как наиболее полного.

void Log::writeError(const std::string& message)
{
    if (mDebugLevel >= DEBUG_LEVEL_ERROR) {
        writeMessage(getLogString(message, "error"), MESSAGE_ERROR);
    }
#ifdef _DEBUG
	assert(0);
#endif	
	exit(EXIT_FAILURE);
}

Итак, первым делом проверяется, что уровень подробности допускает вывод ошибок, затем вызывается служебный метод writeMessage, которому передается сообщение и тип сообщения. В результате будет выведено что-то подобное
error: [message]

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

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

В свою очередь writeMessage выглядит следующим образом

void Log::writeMessage(const std::string& message, MessageType type)
{
    std::string text(message);
    std::replace(text.begin(), text.end(), 'n', ' ');
    appendToFile(text);
#ifdef _DEBUG
    writeIDEDebugString(text, type);
#endif
}

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

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

Рисунок 2. Определения макроса-признака отладки для XCode

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

Windows (Visual Studio)

void Log_Windows::writeIDEDebugString(const std::string& message, MessageType type)
{
	OutputDebugStringA(message.c_str());
	OutputDebugStringA("n");
}

Android (Eclipse)

void Log_Android::writeIDEDebugString(const String& message, MessageType type)

{
	switch(type){
		case MESSAGE_INFO:
			__android_log_print(ANDROID_LOG_INFO, "", message.c_str());
			break;
		case MESSAGE_WARNING:
			__android_log_print(ANDROID_LOG_WARN, "", message.c_str());
			break;
		case MESSAGE_ERROR:
			__android_log_print(ANDROID_LOG_ERROR, "", message.c_str());
			break;
	}
}

Как видим, в случае Android получаем дополнительную наглядность: есть возможность выводить сообщения разными цветами. Проблема, выведенная красным цветом, имеет мало шансов ускользнуть от внимания, даже без assert.

Рисунок 3. Выделение цветом сообщений в зависимости от типа в Eclipse

MacOS и iOS (XCode)

void Log_Mac::writeIDEDebugString(const std::string& message, MessageType type)
{
    NSLog(@"%s", message.c_str());
}

С непосредственным выводом разобрались, остается вопрос, как это правильно упаковать в потоки. Ведь все методы вывода мы закрыли.

Для начала определимся с желательной записью. Потоки c++ могут получать параметры вывода тем же способом, которым им передаются данные. Например, так сообщение будет выведено заглавными буквами.

std::cout << std::uppercase << "test" << 'n';

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

Log::error<<"text"<<std::endl;
Log::warning<<"text"<<std::endl;
Log::message<<"text"<<std::endl;

Т.е. информацию о типе сообщения будет содержать сам объект потока. Конечно, стандартными параметрами потоков типа std::uppercase все еще можно пользоваться. Вся функциональность потоков унаследована от классов стандартной библиотеки.

class Streamer : public std::ostream {
    public:
        
        Streamer(MessageType messageType);
        ~Streamer();
        
    private:
        class StringBuffer : public std::stringbuf {
        public:
            Buffer(MessageType messageType);
            ~Buffer();
            virtual int sync();
            
        private:
            MessageType mMessageType;
        };
    };

Для каждого вида потока будет свой объект, поэтому конструкторы принимают параметр MessageType. Сам класс вывода мы наследуем от std::ostream [5], за формирование строки будет отвечать вложенный класс StringBuffer, который в свою очередь унаследован от std::stringbuf [6]. Каждый раз, когда пользователь будет сообщать о завершении формировании сообщения, будет автоматически вызван метод sync, в котором мы и выполним непосредственный вывод. Сообщить о завершении вывода можно стандартными для буферизируемых потоков способами: с помощью вызова метода flush

Log::message<<"text";
Log::message.flush();

или просто добавив в поток std::endl

Log::message<<"text"<<std::endl;

Также нужно связать поток вывода со строковым буфером. Это выполняется в конструкторе

Log::Streamer::Streamer(Log::MessageType messageType)
: std::ostream(new StringBuffer(messageType))
    {
    }

Соответственно при разрушении, буфер нужно самостоятельно уничтожить

Log::Streamer::~Streamer()
{
    delete rdbuf();
}

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

Log::Streamer::StringBuffer:: StringBuffer(Log::MessageType messageType)
: mMessageType(messageType)
{
}

При разрушении на всякий случай вызываем его синхронизацию – это предотвратит «пропадание» сообщения, если программист забудет вызвать flush или endl.

Log::Streamer::Buffer::~Buffer()
{
    pubsync();
}

Чтобы поток имел доступ к закрытому для внешнего мира основному интерфейсу класса Log, поместим его внутрь

class Log
{
public:
        
...
    
	class Streamer : public std::ostream {
...
     };

    static Streamer message;
    static Streamer warning;
    static Streamer error;
...

message warning и error – экземпляры потоков для сообщений каждого типа. Тип сообщения передается им в конструктор

Log::Streamer Log::message(Log::MESSAGE_INFO);
Log::Streamer Log::warning(Log::MESSAGE_WARNING);
Log::Streamer Log::error(Log::MESSAGE_ERROR);

Ну и, наконец, рассмотрим реализацию функции синхронизации строкового буфера потока.

int Log::Streamer::StringBuffer::sync()
{
    if (Log::sInstance == NULL) {
        return 0;
    }
    std::string text(str());
    if (text.empty()) {
        return 0;
    }
    str("");
    switch (mMessageType) {
        case MESSAGE_INFO:
            Log::sInstance->writeMessage(text);
            break;

		case MESSAGE_WARNING:
            Log::sInstance->writeWarning(text);
            break;
            
		case MESSAGE_ERROR:
            Log::sInstance->writeError(text);
            break;
    }
    return 0;
}

Как вложенный класс Log::Streamer::Buffer имеет доступ к закрытой (private) области Log. В уточнении нуждается разве что функция str(). Это довольно странный метод класса std::stringbuf, который одновременно позволяет получать и устанавливать значение буфера. В обеих своих ипостасях он и используется – сначала с помощью этой функции мы получаем строку из буфера, а затем вызовом str("") очищаем буфер.
Все, теперь класс Streamer становится «официальным» интерфейсом Log. Для того, чтобы вывести составное сообщение «i (6) should be in range [1..5]», программисту достаточно написать

Log::warning << "i (" << i << ") should be in range [" << I_MIN << ".." << I_MAX << "]" << std::endl;

Это уже почти так же просто, как вывести гораздо более туманное «wrong i»
Таким образом, был приведен пример достаточно простого класса ведения журнала событий, который может быть легко реализован в самом начале даже самого сжатого по срокам (когда некогда ни писать тесты, ни уговаривать программистов, ни эффективно контролировать их, ни дышать, ни спать) проекта, существенно повысив его качество.

[1] en.wikipedia.org/wiki/Multiple_dispatch
[2] www.cplusplus.com/reference/cstdio/sprintf/
[3] www.cplusplus.com/reference/sstream/stringstream/
[4] www.cplusplus.com/reference/cassert/assert
[5] www.cplusplus.com/reference/ostream/ostream/
[6] www.cplusplus.com/reference/sstream/stringbuf/

Автор: vadim_ig

Источник