Про логирование и как его ускоритьКак-то раз я ускорял логгер через io_uring, т.к. скорость логгера не позволяла совмещать активную торговлю и достаточное количество информации для расследования случившихся инцидентов. Поэтому расскажу что понял на эту тему. Простое логирование состоит из 2х частей: форматирование и вывод. Различные throttle'ры, примочки, фильтры, окрашиватели рассматривать не будем.
Форматирование:
1)
std::stringstream - не стоит, не надо: это медленно.
2)
std::snprintf - не стоит, не надо: медленно, не современно.
3)
std::format, поддерживается только с C++20. Я его не смотрел, но подозреваю, что в текущем виде libfmt будет быстрее.
4)
libfmt - базовый выбор, достаточно быстрый. Для самых критических областей добавляем
FMT_COMPILE, но не повсюду.
5) Не форматировать вообще. Можно складывать бинарные данные в файл (подход
Binlog), либо отправлять куда-то (но это получается уже телеметрия). Но тогда файл требует декодирования отдельной тулзой. Но это можно автоматизировать.
6) Выносить форматирование в отдельный поток. Интересный подход из Quill. Они encode'ят аргументы в буфер, и предполагается, что это быстрее, чем отформатировать. Попробую эту либу, и позже поделюсь впечатлениями.
7) Еще крайне желательно не вычислять формат аргументы, если текущий verbosity все равно не выведет эту строку. Это приводит нас к тому, что нам подходят только макросы в том месте, где юзеры вызывают логирование.
Какие есть
варианты по выводу сформированной строки на file storage:
1) Вывод в файл через:
-
std::ofstream::operator << и
flush-
fwrite +
fflush (glibc)
- один
write syscall
Выдают примерно одинаковые величины задержек. По логике можно представить, что дёрнуть просто syscall дешевле, но по факту разницу сложно увидеть.
В первых двух вариантах можно не делать flush на каждую строку, это сильно быстрее (т.к. данные буферятся в юзерспейсе), но тогда:
- Если долго нет новой строчки, то последнюю можно долго не видеть в логе. Но можно дополнительно flush'ить по таймеру.
- Что-то потеряется при креше, т.к. останется в памяти процесса. Однако это можно достать из кордампа gdb-скриптюней (такое не писал, но выглядит осуществимым).
Проблемы: средняя скорость min/avg: до 1 микроса, но периодически
write может сделать серьезный пик, уходя в запись на устройство на 1-5мс (это на nvme). Можно попробовать понастраивать механизм сбрасывания dirty pages (см.
sysctl -a | grep vm.dirty_).
2) Передаём задачу записи в отдельный поток. Так делает, например,
Quill. Это очень быстро (скорость: от сотни наносекунд, если используете простую очередь, mutex и cv, и несколько наносекунд, если пишете в ring buffer (если не боитесь переполнения и нет параллельных вызовов)), но имеет свои недостатки:
- Этому отдельному потоку тоже нужно какое-то (неторговое) ядро.
- При креше вы можете потерять несколько последних строк (а именно они обычно нужны при креше). Снова можно пробовать выковыривать из крешдампа, но это неудобно. Скорее всего, можно дождаться дозаписи в крэшхэндлере.
3) Запись в ядре через
io_uring: выглядит интересно, но имеет свои сложности: код надо очень аккуратно писать, понимать как настраивать kworker'ы (куда их пиннить, какие там размеры буферов и т.п.). Подходит для kernel'ов старше 5.1. В случае креша без специальных приседаний ядро не дозапишет строки. Я эту штуку использовал, и было интересно познакомиться с механизмом. Ждал дозаписи строк в крэш-хэндлере.
4) Запись в отдельном своём сервисе. Как ему максимально быстро передать строку - отдельный непростой вопрос, который может сильно всё усложнить. Сервисом тоже нужно управлять, деплоить, он тоже может упасть.
5) Вариант предыдущего пункта: выводить в stdout и писать в файловую систему через стандартный сервис (journald, dockerd). Тоже один syscall, поэтому по скорости как запись в файл, но без пиков в несколько миллисов. Довольно быстро, стандартно. Легко поддержать ротацию. Если процесс крашнется сразу после лог строчки, то демон всё дозапишет.
Дополняйте, если что, или поправьте.
