26.06.2025 16:01
andrey0917 19 1500 Источник

В .NET 9 появилась интересная функциональность — Log Buffering, которая позволяет буферизовать логи в памяти и выводить их только при определенных условиях. Меня заинтересовала эта идея, что я решил реализовать аналогичный механизм для Go. Так появился EmitLog — пакет для условной буферизации логов.

Проблема традиционного логирования

Представьте типичный веб-сервис с детальным логированием:

func ProcessPayment(ctx context.Context, paymentID string) error {
    log.Debug("Starting payment processing")
    log.Debug("Validating payment data")
    log.Debug("Checking user balance")
    log.Debug("Connecting to payment gateway")
    log.Info("Payment processed successfully")
    return nil
}

При высокой нагрузке такой сервис генерирует огромное количество логов:

  • 99% успешных транзакций = миллионы ненужных debug-логов

  • Высокие расходы на хранение в системах типа ELK, Datadog

  • Замедление поиска важной информации в море рутинных записей

Но если убрать debug-логи совсем, то при ошибке мы потеряем контекст происходящего.

Решение: условная буферизация

EmitLog решает эту дилемму:

  1. Буферизует все логи запроса в памяти

  2. Анализирует результат выполнения

  3. Решает — сохранить логи или отбросить

// При ошибке — видим полный контекст
[ERROR] Payment failed: insufficient funds
[DEBUG] Starting payment processing
[DEBUG] Validating payment data  
[DEBUG] Checking user balance
[INFO] User balance: $50, required: $100
// При успехе — логи отбрасываются (или сохраняются с вероятностью 5%)

Цепочка контекста логирования

Вот как выглядит полный flow:

HTTP Request → Middleware создает BufferingWriter
                    ↓
              Создает logger с контекстом запроса
                    ↓
              Logger помещается в context.Context
                    ↓
              Handler извлекает logger: GetLoggerFromContext(ctx)
                    ↓
              Все логи пишутся в буфер в памяти
                    ↓
              [Возникла ошибка?]
                 ↙        ↘
              Да           Нет
               ↓            ↓
         Flush всех    [Random < SaveRate?]
           логов          ↙        ↘
                        Да          Нет
                         ↓           ↓
                   Сохранить    Отбросить

Практическое использование

Базовая настройка

func main() {
    // Настраиваем zerolog
    log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr})
    
    // Конфигурация EmitLog
    config := emitlog.Config{
        SaveRate:         10.0,      // 10% успешных запросов
        BufferingEnabled: true,      
        FlushOnError:     true,      // Всегда при ошибках
        FlushOnWarn:      false,     // Игнорируем warnings
        BufferSize:       64 * 1024, // 64KB на запрос
    }
    
    // Применяем middleware
    handler := emitlog.Middleware(config, os.Stderr)(mux)
    http.ListenAndServe(":8080", handler)
}

Использование в хендлерах

func ProcessOrderHandler(w http.ResponseWriter, r *http.Request) {
    // Извлекаем настроенный logger из контекста
    logger := emitlog.GetLoggerFromContext(r.Context())
    
    logger.Debug().Msg("Parsing order request")
    
    var order Order
    if err := json.NewDecoder(r.Body).Decode(&order); err != nil {
        logger.Error().Err(err).Msg("Failed to parse order")
        http.Error(w, "Bad request", 400)
        return // Все debug-логи будут выведены!
    }
    
    logger.Debug().
        Str("order_id", order.ID).
        Float64("amount", order.Amount).
        Msg("Processing order")
    
    if err := processPayment(order); err != nil {
        logger.Error().Err(err).Msg("Payment failed")
        http.Error(w, "Payment failed", 500)
        return // Видим полный контекст ошибки
    }
    
    logger.Info().Msg("Order processed successfully")
    w.WriteHeader(200)
    // При успехе логи сохранятся только с вероятностью SaveRate
}

Преимущества подхода

1. Снижение объема логов

Традиционное логирование:

  • 1M запросов/день × 10 логов/запрос = 10M записей

  • При SaveRate = 5%: 50K записей + логи всех ошибок

  • Экономия: 95%+ на хранении

2. Полный контекст при ошибках

Когда что-то идет не так, вы видите всю историю запроса:

  • Все debug-сообщения

  • Промежуточные состояния

  • Точную последовательность операций

3. Производительность

  • Снижение I/O: меньше записей на диск/сеть

  • Батчинг: при сбросе логи пишутся одним блоком

4. Гибкая конфигурация

// Development
config.BufferingEnabled = false  // Видим все сразу
config.SaveRate = 100.0          // Сохраняем все

// Staging  
config.SaveRate = 50.0           // Половину для анализа
config.FlushOnWarn = true        // Warnings тоже важны

// Production
config.SaveRate = 5.0            // Только 5% успешных
config.BufferSize = 128 * 1024   // Больше буфер

Когда использовать EmitLog

✅ Идеально подходит для:

  • Высоконагруженных API с детальным логированием

  • Микросервисов с дорогой инфраструктурой логирования

  • Систем, где ошибки требуют полного контекста для отладки

❌ Не подходит для:

  • Критичных аудит-логов (compliance)

  • Реального времени мониторинга

  • Маленьких приложений с небольшим объемом логов

Заключение

Код проекта доступен на GitHub

Буду рад фидбеку и предложениям по развитию проекта!

мой телерамм для связи https://t.me/atsaregorodtsev

Комментарии (19)


  1. yellow79
    26.06.2025 16:20
    #28490414

    У Go давно появился отличный логгер из коробки, а люди зачем-то продолжают использовать древние решения. И не просто древние решения, а обёртки над ними, преподнося это как киллер-фичу. Кажется было бы на много лучше написать реализацию подобного функционала представив её в виде `slog.Handler`тогда подключить ваше решение не составить никакого труда. А так, просто представьте, надо будет везде внедрять зависимость в виде `emitlog`, кто на такое пойдёт? А потом ещё выпиливать если вдруг что-то пойдёт не так. Ну уж нет.


    1. autyan
      26.06.2025 16:20
      #28490446

      Полностью согласен. И даже до изменений в стандартных логах, go-путь подразумевает самостоятельное написание такой мелочи, как логгер, вместо добавления очередной зависимости.


      1. PrinceKorwin
        26.06.2025 16:20
        #28490534

        go-путь подразумевает самостоятельное написание такой мелочи, как логгер, вместо добавления очередной зависимости.

        Хм. Интересный подход. 1) А как в таком случае унифицировать формат вывода логов из вашего кода и из стороннего, который вы через депенденси подключили? 2) И как управлять какие логи вы хотите видеть, а какие убрать? 3) А если хотите дообогатить логи чем-то из контекста?


        1. autyan
          26.06.2025 16:20
          #28490624

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


          1. PrinceKorwin
            26.06.2025 16:20
            #28490940

            Как вы предлагаете управлять "всем" в сторонних библиотеках которые вы подключаете?


            1. dopusteam
              26.06.2025 16:20
              #28492120

              Конфигурацией, очевидно


              1. PrinceKorwin
                26.06.2025 16:20
                #28492162

                эм. при таком подходе у каждой библиотеки будет своя конфигурация да и не факт что она вообще будет. не очень понимаю преимуществ такого подхода.


    1. aleshka_dolohov
      26.06.2025 16:20
      #28490456

      Ну, тут же больше про концепцию, реализовать можно на любом популярном логгере.


    1. andrey0917 Автор
      26.06.2025 16:20
      #28490832

      никто не мешает использовать подход который я предложил к slog, и никто не заставляет тянуть именно мою либу. можно просто скопировать код и использовать


    1. Maksclub
      26.06.2025 16:20
      #28492140

      slog вполне подходит для реализации концепции из статьи, в чем претензия?


  1. aleshka_dolohov
    26.06.2025 16:20
    #28490490

    Как util либа - хорошая идея.


  1. Sly_tom_cat
    26.06.2025 16:20
    #28491046

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

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

    Допустим API отдает огромные простынки ответов, их что бы полностью вывести (с учетом того что эти логи нужно как-то обрабатывать) иногда приходится делить на несколько строк да еще при этом вводить искусственный ID и порядковый номер для того, чтобы потом можно было собрать и запрос и разбитый на части ответ на него (ведь логи могут писаться параллельно из множества потоков). И такая ситуация - отнюдь не редкость. И вот тут в сообщениях может быть такая набивка из соседних потоков, что никаких буферов не хватит, чтобы собрать нужный ответ после ошибки.

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


    1. andrey0917 Автор
      26.06.2025 16:20
      #28491068

      логика такая: в контексет есть логгер и у него свой буфер, пока не будет вызван например log.Err все логи пишутся в буфер - а после уже в указанные врайтер. если буфер переполняется - логи тоже скидываются в финальный врайтер.

      тут именно речь про логирование цепочки действия целиком - поэтому логгер прокидывется через контекст

      поэтому можно получать логи целиком от одног контекста если в них были ошибки


      1. Sly_tom_cat
        26.06.2025 16:20
        #28491186

        Для этого нужно в каждый хендлер вставлять свой логгер-обертку. Такое не слишком удобно. Логгирование проще делать централизованно либо как топлевел мидлвере, либо вообще что-то глобальное.


        1. andrey0917 Автор
          26.06.2025 16:20
          #28491210

          так у меня и есть мидлвере с таким подходом


          1. Sly_tom_cat
            26.06.2025 16:20
            #28491456

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


            1. andrey0917 Автор
              26.06.2025 16:20
              #28491466

              а почему вы считаете что я сделал штуку для всего на свете?


              1. Sly_tom_cat
                26.06.2025 16:20
                #28496096

                Да я без претензий, в вашей концепции есть неплохая, интересная идея... И я пытаюсь ее натянуть на разные сценарии.

                Только вот я в логгировани пришел немного к другому подходу.

                Я в одном проекте сделал так, что по сути выводится только уведомления о важных событиях и ошибки. Так вот понимая сложность сбора контекста ошибки у меня ошибка собирается с деталями по всему стеку вызова и вот с ее адекватным форматированием (с учетом ограничения на длину строки) пришлось повозится изрядно. Но в такой схеме debug вообще не нужен. Я там в ошибку выкидываю все, что нужно для того, что бы понять почему именно там произошла ошибка, где и с какими данными.

                Один раз правда не хватило этого пришлось снимать трейсы, что бы понять, что там внезапно начинает выедать один CPU.

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


  1. cupraer
    26.06.2025 16:20
    #28495678

    А что не так с телеметрией, в которой помимо всего есть и вложенные спаны дл отслеживания контекста?