Как не утонуть в одинаковых ошибках: CollapseXXX в logme
Одинаковые ошибки в логах — одна из самых неприятных проблем production-диагностики. Иногда проблема не в том, что логов мало, а в том, что их слишком много. Когда ошибка повторяется в цикле, на каждом reconnect-е, на каждом retry или на каждом запросе, лог быстро превращается в поток почти одинаковых строк.
Например, внешний backend стал недоступен, а сервис продолжает пытаться к нему подключиться:
backend connection failed backend connection failed backend connection failed backend connection failed backend connection failed backend connection failed
Формально каждое сообщение правдивое. Но для человека такой лог почти бесполезен. Он не помогает быстрее понять причину, зато раздувает файл, вытесняет соседние события и делает расследование тяжелее. Важная информация часто находится не в тысячном повторе той же ошибки, а в событиях до первого сбоя или сразу после изменения состояния системы.
Для таких случаев в системе логирования logme есть семейство collapse-макросов. Их задача — не скрыть ошибку, а убрать лишний шум вокруг повторов.
Что делает Collapse
Collapse позволяет свернуть серию одинаковых сообщений. Первое сообщение печатается сразу, чтобы факт проблемы был виден. Повторяющиеся сообщения с того же места в коде временно подавляются. Когда накопилось заданное количество повторов, logme печатает summary с количеством скрытых сообщений.
Например:
LogmeW_Collapse(100, "backend connection failed");
Первое сообщение будет выведено сразу. Потом одинаковые повторы будут подавляться. Когда счетчик повторов достигнет лимита, logme выведет сообщение с тем же текстом, но с указанием количества повторов:
repeated 100 times: backend connection failed
Формат summary остается обычной частью logme formatting path. Это важно: collapse не создает отдельный необычный формат лога. Он просто передает в запись информацию о том, что сообщение повторялось.
Зачем нужен CollapseEvery
Count-based collapse хорошо работает, когда повторения частые, но не экстремальные. Например, если reconnect происходит раз в секунду, то Collapse(60) даст примерно одно summary в минуту.
Но бывают другие ситуации. Ошибка может печататься внутри быстрого цикла. В таком случае даже лимит в тысячу повторов может не помочь. Если код способен породить сотни тысяч одинаковых сообщений в секунду, то count-based collapse все равно может слишком часто пропускать summary в лог.
Для таких случаев нужен time-based вариант:
LogmeW_CollapseEvery(1000, "backend connection failed");
Здесь смысл другой. Первое сообщение печатается сразу. Потом такие же сообщения подавляются в течение заданного интервала. Когда интервал прошел и то же сообщение снова пришло, logme печатает запись с накопленным счетчиком повторов.
То есть Collapse(1000) говорит: “напечатай summary после тысячи повторов”.
А CollapseEvery(1000) говорит: “не печатай эту повторяющуюся ошибку чаще одного раза в секунду, но сохрани счетчик подавленных повторов”.
Это не замена Every. У Every другая задача: просто ограничить частоту вывода сообщения. CollapseEvery сохраняет collapse-семантику: первое сообщение видно сразу, повторы подавляются, а затем печатается summary с количеством накопленных повторов.
Почему это не просто rate limit
На первый взгляд CollapseEvery похож на обычный rate limiting. Но важное отличие в том, что он работает с повторяющимся сообщением как с логической серией.
LogmeW_Every(1000, ...) полезен, когда нужно печатать сообщение не чаще раза в секунду. Но он не сообщает, сколько вызовов было подавлено.
LogmeW_CollapseEvery(1000, ...) предназначен для другой ситуации: сообщение важно, но повторы создают шум. Поэтому logme не просто ограничивает частоту, а еще и сохраняет счетчик повторений.
В результате в логе видно не только то, что ошибка продолжается, но и масштаб проблемы:
backend connection failed repeated 245731 times: backend connection failed
Для production-диагностики это намного полезнее, чем просто периодически видеть ту же строку без понимания, сколько раз она реально происходила.
Когда использовать Collapse, а когда CollapseEvery
Если сообщение повторяется с умеренной скоростью и вас интересует количество повторов, удобно использовать обычный Collapse.
Например:
LogmeW_Collapse(10, "configuration reload failed");Если же сообщение может появляться очень быстро, лучше использовать CollapseEvery:
LogmeW_CollapseEvery(1000, "backend connection failed");Такой вариант особенно уместен для retry loops, polling loops, reconnect loops и ошибок внутри циклов, которые в плохом состоянии системы могут выполняться очень часто.
Важно понимать, что CollapseEvery не претендует на минимальную цену вызова. Это не macro для массового применения в каждом горячем месте. Он использует специальную collapse-логику, сравнивает ключ сообщения и хранит состояние call site. Его задача — оптимизировать содержимое лога в специальных случаях, а не заменить обычное логирование.
Почему одинаковые ошибки не всегда одинаковые
В реальных логах повторяющиеся ошибки часто отличаются деталями. Например:
request=1001 backend connection failed after 10ms request=1002 backend connection failed after 12ms request=1003 backend connection failed after 9ms
Для человека это одна и та же проблема: backend недоступен. Но для простого сравнения строк это разные сообщения. Request id и elapsed time делают каждую строку уникальной.
Для таких случаев в logme есть CollapseIgnore.
LogmeW_CollapseIgnore( "request=[0-9]+|after [0-9]+ms" , 100 , "request=%d backend connection failed after %dms" , requestId , elapsedMs );
Регулярное выражение используется только для сравнения. Из форматированного сообщения временно удаляются volatile-части, и уже после этого logme решает, является ли сообщение повтором. В сам лог при этом попадает оригинальный текст сообщения.
CollapseIgnoreEvery
Time-based collapse тоже можно совмещать с игнорированием volatile-частей:
LogmeW_CollapseIgnoreEvery( "request=[0-9]+|after [0-9]+ms" , 1000 , "request=%d backend connection failed after %dms" , requestId , elapsedMs );
Это полезно, когда ошибка повторяется очень быстро, но каждая строка содержит request id, correlation id, счетчик, timestamp или другое поле, которое меняется при каждом вызове.
Без ignore-логики такие строки не будут считаться одинаковыми. С CollapseIgnoreEvery они могут быть свернуты в одну серию, а лог останется компактным.
Например, вместо тысяч строк с разными request id можно получить одну понятную запись с количеством повторов.
Что происходит при смене сообщения
Collapse работает с одним call site и одним comparison key. Если с того же места в коде пришло другое сообщение, logme считает, что началась новая серия. Pending summary по старому key при этом не печатается.
Это важное поведение. Collapse не пытается генерировать дополнительную запись “задним числом” при смене сообщения. Он просто начинает новую серию.
Такой подход проще и предсказуемее. Если сообщение A повторялось, но затем пришло сообщение B, logme не вставляет перед B дополнительное summary для A. Новое сообщение печатается нормально и становится новым ключом для этого call site.
Многострочные сообщения
Collapse работает с логическим сообщением, а не с визуальной строкой на экране. Если несколько строк должны рассматриваться как одно повторяющееся событие, их лучше сформировать как одно log message с \n внутри.
Например:
backend request failed host=api.example.com operation=update-profile
Такое сообщение может быть одним логическим событием. Если оно повторяется, его можно сворачивать как единый блок.
Если же каждая строка печатается отдельным log call, collapse будет работать с каждой строкой отдельно. Иногда это нормально, но для повторяющихся блоков чаще лучше собрать связанный контекст в одно сообщение.
Когда collapse использовать нельзя
Collapse не подходит для audit-логов, billing-событий, security decisions и любых записей, где важен каждый отдельный факт. Если каждое событие должно быть сохранено, его нельзя сворачивать.
Также нужно аккуратно использовать CollapseIgnore. Нельзя игнорировать поля, которые меняют смысл ошибки. Например, если user, host, operation или error code важны для расследования, их нельзя бездумно удалять из comparison key.
Хорошее правило простое: игнорировать можно только те части сообщения, которые создают шум, но не меняют причину события.
Практическая схема выбора
Если сообщение нужно показать только один раз, используйте Once.
Если сообщение нужно просто показывать не чаще заданного интервала и счетчик повторов не важен, используйте Every.
Если сообщение повторяется и нужно summary по числу повторов, используйте Collapse.
Если сообщение повторяется слишком быстро и нужно ограничить вывод по времени, используйте CollapseEvery.
Если строки логически одинаковые, но содержат volatile-поля, используйте CollapseIgnore или CollapseIgnoreEvery.
Так получается понятная лестница инструментов. Простые случаи закрываются простыми макросами. Для более шумных и сложных production-сценариев есть collapse-механика.
Итог
Collapse, CollapseEvery, CollapseIgnore и CollapseIgnoreEvery делают поддержку повторяющихся сообщений в logme значительно мощнее.
Collapse агрегирует повторы по счетчику. CollapseEvery агрегирует повторы по времени. CollapseIgnore позволяет считать одинаковыми сообщения с изменяющимися деталями. CollapseIgnoreEvery объединяет оба подхода и особенно полезен для быстрых циклов с volatile-полями.
Главная идея остается простой: лог должен помогать человеку понять, что произошло. Если тысяча одинаковых строк не добавляет понимания, их лучше свернуть в одну понятную запись с количеством повторов.