Как логировать сообщения с временной меткой, включающей микросекунды, в C++?

Ответ

В современном C++ для логирования с точностью до микросекунд удобно использовать библиотеку <chrono>. Вот практический пример функции логирования:

#include <chrono>
#include <iostream>
#include <iomanip>
#include <ctime>

void log_with_microseconds(const std::string& message) {
    // 1. Получаем текущее время
    auto now = std::chrono::system_clock::now();

    // 2. Преобразуем в time_t для форматирования даты/времени
    std::time_t time_now = std::chrono::system_clock::to_time_t(now);

    // 3. Вычисляем количество микросекунд с начала секунды
    auto since_epoch = now.time_since_epoch();
    auto seconds = std::chrono::duration_cast<std::chrono::seconds>(since_epoch);
    auto microseconds = std::chrono::duration_cast<std::chrono::microseconds>(since_epoch - seconds);

    // 4. Форматируем и выводим
    // std::localtime не является потокобезопасным, в production-коде используйте localtime_r
    std::cout << std::put_time(std::localtime(&time_now), "%Y-%m-%d %H:%M:%S.")
              << std::setfill('0') << std::setw(6) << microseconds.count()
              << " - " << message << std::endl;
}

// Пример использования
int main() {
    log_with_microseconds("Запуск приложения");
    // ... какой-то код ...
    log_with_microseconds("Выполнение завершено");
    return 0;
}
// Вывод: 2024-05-15 14:30:25.123456 - Запуск приложения

Ключевые моменты:

  • std::chrono::system_clock предоставляет время, привязанное к системным часам (календарное время).
  • duration_cast используется для преобразования временного интервала в нужные единицы.
  • %Y-%m-%d %H:%M:%S — стандартный формат даты и времени.
  • std::setw(6) гарантирует, что микросекунды будут выведены как 6 цифр (дополнены нулями слева).

Для измерений интервалов (бенчмаркинг) вместо system_clock лучше использовать std::chrono::steady_clock, который монотонен и не подвержен корректировкам системного времени, но он не предназначен для получения календарного времени для логов.

Ответ 18+ 🔞

А, ну вот, смотри, тут про логирование с микросекундами в C++. Ёпта, звучит как какая-то высшая математика, но на самом деле всё проще, чем кажется. Сейчас разложу по полочкам, чтобы даже мой кот, сука собака, понял.

Так, первое — библиотека <chrono>. Это не просто библиотека, это твой новый лучший друг, если хочешь знать, когда что-то произошло точнее, чем «вчера, кажется». Без неё ты как слепой кот в подвале — нихуя не видишь, что происходит.

Вот смотри на этот код. Первая строчка — ловим текущее время. std::chrono::system_clock::now(). Это как спросить у системы: «Эй, сука, который час?» И она тебе отвечает очень точным, но совершенно нечитаемым для человека способом.

auto now = std::chrono::system_clock::now();

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

std::time_t time_now = std::chrono::system_clock::to_time_t(now);

А вот тут самое интересное. Сами секунды — это хорошо, но где наши микросекунды? Они же спрятаны в дробной части! Берём нашу временную точку (since_epoch), вычленяем из неё целые секунды, а потом смотрим, что осталось. Остаток — это и есть наши микросекунды (или наносекунды, если очень захотеть). duration_cast — это такой волшебный нож, который отрезает ровно то, что нужно.

auto since_epoch = now.time_since_epoch();
auto seconds = std::chrono::duration_cast<std::chrono::seconds>(since_epoch);
auto microseconds = std::chrono::duration_cast<std::chrono::microseconds>(since_epoch - seconds);

Ну и финальный акт — вывод. Берём наше преобразованное в структуру tm время (std::localtime(&time_now)), форматируем его в красивую строку с помощью std::put_time, и доклеиваем микросекунды. std::setw(6) и std::setfill('0') — это чтобы микросекунды всегда были шестизначными, даже если это 000042. Иначе будет пиздец и некрасиво.

std::cout << std::put_time(std::localtime(&time_now), "%Y-%m-%d %H:%M:%S.")
          << std::setfill('0') << std::setw(6) << microseconds.count()
          << " - " << message << std::endl;

Важный момент, на котором можно обжечься, как хуй на морозе: std::localtime — не потокобезопасная функция. В продакшене, где всё бегает в двадцати потоках одновременно, это прямой путь в ад. Там нужно использовать её потокобезопасные аналоги, типа localtime_r. Иначе будет весело, когда логи начнут показывать 1985-й год.

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

Для замеров интервалов есть священный std::chrono::steady_clock. Он монотонный. Его нельзя сдвинуть или подкрутить. Он тикает себе равномерно, как часы у упоротого физика. Но, блядь, он не умеет говорить «сегодня 15 мая». Он умеет только говорить: «С момента старта прошло вот столько-то наносекунд». Для бенчмарков — идеально. Для логов — нихуя не годится.

Так что запомни: хочешь написать в лог, когда случилась ошибка — system_clock. Хочешь понять, не жрёт ли твой новый алгоритм overдохуища времени — steady_clock. Не перепутай, а то будет тебе хиросима в отладке.