diff options
| author | iofik <[email protected]> | 2026-02-19 22:43:26 +0300 |
|---|---|---|
| committer | iofik <[email protected]> | 2026-02-19 23:07:43 +0300 |
| commit | ed109965ec70b4e46ead9312cc5e33c2e561d154 (patch) | |
| tree | c50097f9a8c21c64e1ff0858ef29774a6f70b134 /library/cpp | |
| parent | 107ef4754ad71c4d47206e55f20433aeb7d99b60 (diff) | |
/2: Use our internal logger header, add logging metrics
# Улучшения библиотеки логирования и переход на троттлинг логов
## Описание
Этот PR содержит улучшения системы логирования unified\_agent с акцентом на предотвращение флуда логов и добавление метрик логирования.
## Основные изменения
### 1. Улучшения библиотеки логирования (`library/cpp/unified_agent_client/logger`)
- **Встроенный троттлинг логов**: Добавлена поддержка ограничения частоты логирования на уровне библиотеки
- Новые макросы `YLOG_*_T` с автоматическим троттлингом (20 логов на 10 секунд по умолчанию)
- Независимый троттлинг для каждой точки логирования (по `__FILE__:__LINE__`)
- Автоматический подсчет подавленных сообщений с выводом `[+N suppressed]`
- **Метрики логирования**: Добавлены счетчики для мониторинга активности логирования
- `RecordsReceived` - общее количество попыток логирования
- `RecordsDropped` - количество подавленных сообщений из-за троттлинга
- Счетчики передаются через `TLogger::TCounters` при создании логгера
- **Оптимизация производительности**:
- Использование `GetCycleCount()` для быстрого получения времени (вместо системных вызовов)
- Relaxed memory ordering для атомарных операций (достаточно для троттлинга)
- Минимальные накладные расходы при отключенном логировании
### 2. Переход всех логов агента на троттлинг
- **Унификация макросов**: Все макросы `YLOG_*` в `logbroker/unified_agent/common/util/logger.h` теперь используют троттлинг
- `YLOG_DEBUG`, `YLOG_INFO`, `YLOG_WARNING`, `YLOG_ERROR` и т.д. теперь автоматически применяют троттлинг
- Старые макросы `YLOG_*_F` теперь алиасы для новых троттлированных версий
- Обратная совместимость полностью сохранена
- **Обновление документации**: Файл `for_ai_cpp.md` обновлен с новыми рекомендациями по логированию
### 3. Интеграция метрик логирования в телеметрию
- **Новые счетчики в `TAgentLogCounters`**:
- `RecordsReceived` - rate метрика `agent.log.records_received`
- `RecordsDropped` - rate метрика `agent.log.records_dropped`
- **Экспорт метрик**: Метрики логирования автоматически собираются и отправляются в телеметрию агента
- **Рефакторинг конструктора `TAgent`**:
- Упрощена передача счетчиков через структуру `TAgent::TCounters`
- Счетчики логирования передаются в `TLogger` при инициализации
### 4. Тесты
- **Перенос тестов**: Тесты логирования перемещены из `logbroker/unified_agent/tests/gtests/logger_tests` в `library/cpp/unified_agent_client/ut`
- **Расширенное покрытие**:
- Тесты базового троттлинга
- Тесты счетчика подавленных сообщений
- Тесты независимого троттлинга для разных точек логирования
- Тесты форматирования сообщений
- Тесты счетчиков метрик
### 5. Исправления и улучшения
- **Удаление дублирования кода**: Логика троттлинга теперь находится только в `library/cpp/unified_agent_client/logger.cpp`
- **Упрощение API**: Удален отдельный файл `logbroker/unified_agent/common/util/logger.cpp`
- **Обновление импортов**: Все файлы обновлены для использования правильных заголовочных файлов
## Преимущества
1. **Защита от флуда логов**: Автоматическое ограничение частоты логирования предотвращает переполнение логов
2. **Наблюдаемость**: Метрики логирования позволяют отслеживать активность и проблемы с логированием
3. **Производительность**: Минимальные накладные расходы благодаря оптимизированной реализации
4. **Простота использования**: Троттлинг работает автоматически, не требует изменений в коде
5. **Обратная совместимость**: Все существующие макросы продолжают работать
## Тестирование
- ✅ Все unit-тесты логирования проходят
- ✅ Integration тесты обновлены (исключение нестабильной метрики `RecordsReceived` из сравнений)
- ✅ Проверена работа троттлинга в реальных условиях
commit_hash:75fc97a8576114446bfb9ec11efbb80df322e443
Diffstat (limited to 'library/cpp')
| -rw-r--r-- | library/cpp/unified_agent_client/client_impl.cpp | 5 | ||||
| -rw-r--r-- | library/cpp/unified_agent_client/logger.cpp | 155 | ||||
| -rw-r--r-- | library/cpp/unified_agent_client/logger.h | 153 | ||||
| -rw-r--r-- | library/cpp/unified_agent_client/ut/logger_ut.cpp | 149 | ||||
| -rw-r--r-- | library/cpp/unified_agent_client/ut/ya.make | 12 | ||||
| -rw-r--r-- | library/cpp/unified_agent_client/ya.make | 1 |
6 files changed, 388 insertions, 87 deletions
diff --git a/library/cpp/unified_agent_client/client_impl.cpp b/library/cpp/unified_agent_client/client_impl.cpp index 2e350d9a133..bddba4cf302 100644 --- a/library/cpp/unified_agent_client/client_impl.cpp +++ b/library/cpp/unified_agent_client/client_impl.cpp @@ -44,7 +44,8 @@ namespace NUnifiedAgent::NPrivate { , ForkProtector(forkProtector) , Counters(parameters.Counters ? parameters.Counters : MakeIntrusive<TClientCounters>()) , Log(parameters.Log) - , MainLogger(Log, MakeFMaybe(Parameters.LogRateLimitBytes)) + , MainLogger(Log, MakeFMaybe(Parameters.LogRateLimitBytes), + TLogger::TCounters{.DroppedBytes = &Counters->ClientLogDroppedBytes}) , Logger(MainLogger.Child(Sprintf("ua_%" PRIu64, Id.fetch_add(1)))) , Channel(nullptr) , Stub(nullptr) @@ -55,8 +56,6 @@ namespace NUnifiedAgent::NPrivate { , Destroyed(false) , Lock() { - MainLogger.SetDroppedBytesCounter(&Counters->ClientLogDroppedBytes); - if (ForkProtector != nullptr) { ForkProtector->Register(*this); } diff --git a/library/cpp/unified_agent_client/logger.cpp b/library/cpp/unified_agent_client/logger.cpp index e78a81d8d87..af126f521de 100644 --- a/library/cpp/unified_agent_client/logger.cpp +++ b/library/cpp/unified_agent_client/logger.cpp @@ -6,12 +6,52 @@ #include <library/cpp/logger/log.h> #include <util/datetime/base.h> +#include <util/datetime/cputimer.h> #include <util/stream/str.h> #include <util/system/getpid.h> #include <util/system/thread.h> namespace NUnifiedAgent { namespace { + // Check if we should log this message (throttling logic) + // Returns: {shouldLog, droppedCount} + // + // Guarantees: + // 1. Prevents log floods - limits logs to ~maxLogsPerSlot per slot + // 2. Every dropped log is counted, but it can be reported later than next logged line + // + // Memory ordering: relaxed should be sufficient here. + // Logs near slot boundaries may be dropped even though the new slot has started, + // or may pass even though the old slot quota is exceeded. This is acceptable for + // throttling - we need approximate rate limiting, not perfect precision. + // Stronger memory ordering cannot eliminate these inherent race conditions. + std::pair<bool, ui32> ShouldLogThrottled(TLogger::TThrottleState& state, ui32 maxLogsPerSlot, ui32 slotSeconds) { + static const ui64 cyclesPerSecond = GetCyclesPerMillisecond() * 1000; + const ui32 newSlot = GetCycleCount() / cyclesPerSecond / slotSeconds; + ui32 oldSlot = state.TimeSlot.load(std::memory_order_relaxed); + + // New slot - try to update the time slot + if (oldSlot != newSlot) { + // The race winner updates the time slot and resets the Logged counter + if (state.TimeSlot.compare_exchange_strong(oldSlot, newSlot, std::memory_order_relaxed)) { + state.Logged.store(1, std::memory_order_relaxed); + const ui32 dropped = state.Dropped.exchange(0, std::memory_order_relaxed); + return {true, dropped}; + } + } + + // Same slot (including the race loosers) - check if we can log + const ui32 logged = state.Logged.fetch_add(1, std::memory_order_relaxed); + if (logged < maxLogsPerSlot) { + // Under limit - log it + return {true, 0}; + } + + // Over limit - drop it + state.Dropped.fetch_add(1, std::memory_order_relaxed); + return {false, 0}; + } + TString FormatLogLine(ELogPriority logLevel, const TStringBuf message, const TString& scope) { TString result; { @@ -30,32 +70,46 @@ namespace NUnifiedAgent { } TLogger::TThrottlerWithLock::TThrottlerWithLock(size_t rateLimitBytes) - : Throttler(rateLimitBytes, rateLimitBytes / 2) - , Lock() + : Throttler_(rateLimitBytes, rateLimitBytes / 2) + , Lock_() { } bool TLogger::TThrottlerWithLock::TryConsume(double tokens) { - with_lock(Lock) { - return Throttler.TryConsume(tokens); + with_lock(Lock_) { + return Throttler_.TryConsume(tokens); } } - TLogger::TLogger(TLog& log, TFMaybe<size_t> rateLimitBytes) - : DefaultLogContext{log, log.IsNullLog() ? ELogPriority::TLOG_EMERG : log.FiltrationLevel()} - , TracingLogContexts() + TLogger::TLogger(TLog& log, TFMaybe<size_t> rateLimitBytes, TCounters counters) + : DefaultLogContext_{log, log.IsNullLog() ? ELogPriority::TLOG_EMERG : log.FiltrationLevel()} + , TracingLogContexts_() , CurrentLogContext_() - , Errors(nullptr) - , DroppedBytes(nullptr) - , Throttler(rateLimitBytes.Defined() ? MakeHolder<TThrottlerWithLock>(*rateLimitBytes) : nullptr) - , Lock() + , Counters_(counters) + , MaxLogsPerSlot_(0) + , SlotSeconds_(0) + , Throttler_(rateLimitBytes.Defined() ? MakeHolder<TThrottlerWithLock>(*rateLimitBytes) : nullptr) + , Lock_() { - SetCurrentLogContext(DefaultLogContext); + SetCurrentLogContext(DefaultLogContext_); + } + + TLogger::TLogger(TLog& log, TFMaybe<size_t> rateLimitBytes, ui32 maxLogsPerSlot, ui32 slotSeconds, TCounters counters) + : DefaultLogContext_{log, log.IsNullLog() ? ELogPriority::TLOG_EMERG : log.FiltrationLevel()} + , TracingLogContexts_() + , CurrentLogContext_() + , Counters_(counters) + , MaxLogsPerSlot_(maxLogsPerSlot) + , SlotSeconds_(slotSeconds) + , Throttler_(rateLimitBytes.Defined() ? MakeHolder<TThrottlerWithLock>(*rateLimitBytes) : nullptr) + , Lock_() + { + SetCurrentLogContext(DefaultLogContext_); } void TLogger::AddLog(TLog& log) { - with_lock(Lock) { - AdditionalLogs.push_back(log); + with_lock(Lock_) { + AdditionalLogs_.push_back(log); } } @@ -63,19 +117,47 @@ namespace NUnifiedAgent { CurrentLogContext_.store(logContext.Log.IsNullLog() ? nullptr : &logContext, std::memory_order_release); } + std::pair<TLog*, ui32> TLogger::Accept(ELogPriority logPriority, NMonitoring::TDeprecatedCounter* errors, TLogger::TThrottleState& state) const { + // Increment received counter if set + if (Counters_.RecordsReceived) { + ++(*Counters_.RecordsReceived); + } + + // Call base Accept to check log level + auto* log = Accept(logPriority, errors); + if (!log) { + return {nullptr, 0}; + } + + // Skip throttling if not configured + if (MaxLogsPerSlot_ == 0 || SlotSeconds_ == 0) { + return {log, 0}; + } + + auto [shouldLog, dropped] = ShouldLogThrottled(state, MaxLogsPerSlot_, SlotSeconds_); + if (shouldLog) { + return {log, dropped}; + } + + if (Counters_.RecordsDropped) { + ++(*Counters_.RecordsDropped); + } + return {nullptr, 0}; + } + void TLogger::Log(TLog& log, ELogPriority logPriority, const TStringBuf message, const TString& scope) const { try { const auto logLine = FormatLogLine(logPriority, NUnifiedAgent::NPrivate::ReplaceNonUTF(message).Data, scope); - if (Throttler && &log == &DefaultLogContext.Log && !Throttler->TryConsume(logLine.size())) { - if (DroppedBytes) { - DroppedBytes->Add(logLine.size()); + if (Throttler_ && &log == &DefaultLogContext_.Log && !Throttler_->TryConsume(logLine.size())) { + if (Counters_.DroppedBytes) { + Counters_.DroppedBytes->Add(logLine.size()); } return; } log.Write(logPriority, logLine); // Write to all additional logs - for (auto& additionalLog : AdditionalLogs) { + for (auto& additionalLog : AdditionalLogs_) { additionalLog.Write(logPriority, logLine); } } catch (...) { @@ -83,15 +165,15 @@ namespace NUnifiedAgent { } void TLogger::StartTracing(ELogPriority logPriority) noexcept { - with_lock(Lock) { + with_lock(Lock_) { auto& logContext = GetOrCreateTracingLogContext(logPriority); SetTracing(logContext, "started"); } } void TLogger::FinishTracing() noexcept { - with_lock(Lock) { - SetTracing(DefaultLogContext, "finished"); + with_lock(Lock_) { + SetTracing(DefaultLogContext_, "finished"); } } @@ -110,7 +192,7 @@ namespace NUnifiedAgent { auto TLogger::GetOrCreateTracingLogContext(ELogPriority logPriority) -> TLogContext& { // Lock must be held - for (const auto& c: TracingLogContexts) { + for (const auto& c: TracingLogContexts_) { if (c->Priority == logPriority) { return *c; } @@ -120,23 +202,32 @@ namespace NUnifiedAgent { newLogContext->Log = TLog("cerr", logPriority); newLogContext->Priority = logPriority; auto* result = newLogContext.Get(); - TracingLogContexts.push_back(std::move(newLogContext)); + TracingLogContexts_.push_back(std::move(newLogContext)); return *result; } + TScopeLogger TLogger::Child(const TString& v, NMonitoring::TDeprecatedCounter* errors) { + return TScopeLogger(this, v, errors == nullptr ? Counters_.Errors : errors); + } + + TScopeLogger::TScopeLogger() - : Logger(nullptr) - , Scope() - , Errors(nullptr) + : Logger_(nullptr) + , Scope_() + , Errors_(nullptr) { } - TScopeLogger::TScopeLogger(TLogger* logger, - const TString& scope, - NMonitoring::TDeprecatedCounter* errors) - : Logger(logger) - , Scope(scope) - , Errors(errors) + TScopeLogger::TScopeLogger(TLogger* logger, TString scope, NMonitoring::TDeprecatedCounter* errors) + : Logger_(logger) + , Scope_(std::move(scope)) + , Errors_(errors) { } + + TScopeLogger TScopeLogger::Child(const TString& v, NMonitoring::TDeprecatedCounter* errors) { + return Logger_ + ? Logger_->Child(Join('/', Scope_, v), errors == nullptr ? Errors_ : errors) + : TScopeLogger(); + } } diff --git a/library/cpp/unified_agent_client/logger.h b/library/cpp/unified_agent_client/logger.h index a9ffcec2946..320b8194869 100644 --- a/library/cpp/unified_agent_client/logger.h +++ b/library/cpp/unified_agent_client/logger.h @@ -23,6 +23,22 @@ } \ } while (false) +// Logging with throttling +#define YLOG_T(logger, logPriority, ...) \ + do { \ + const auto _logPriority = logPriority; \ + static ::NUnifiedAgent::TLogger::TThrottleState _throttleState; \ + auto [_log, _dropped] = logger.Accept(_logPriority, false, _throttleState); \ + if (_log != nullptr) { \ + if (_dropped > 0) { \ + logger.Log(*_log, _logPriority, std::format("{} [+{} suppressed]", \ + ::NUnifiedAgent::YLogFormatMessage(__VA_ARGS__), _dropped)); \ + } else { \ + logger.Log(*_log, _logPriority, ::NUnifiedAgent::YLogFormatMessage(__VA_ARGS__)); \ + } \ + } \ + } while (false) + #define YLOG_EMERG(msg) YLOG(TLOG_EMERG, msg, Logger) #define YLOG_ALERT(msg) YLOG(TLOG_ALERT, msg, Logger) #define YLOG_CRIT(msg) YLOG(TLOG_CRIT, msg, Logger) @@ -48,12 +64,55 @@ #define YLOG_RESOURCES_F(fmt, ...) YLOG_RESOURCES(std::format(fmt, __VA_ARGS__)) #define YLOG_FATAL_F(fmt, ...) YLOG_FATAL(std::format(fmt, __VA_ARGS__)) +// Logging with throttling and metrics increment: +// Errors for ERR+ priorities, RecordsReceived/RecordsDropped +#define YLOG_EMERG_T(...) YLOG_T(Logger, TLOG_EMERG, __VA_ARGS__) +#define YLOG_ALERT_T(...) YLOG_T(Logger, TLOG_ALERT, __VA_ARGS__) +#define YLOG_CRITICAL_T(...) YLOG_T(Logger, TLOG_CRIT, __VA_ARGS__) +#define YLOG_ERROR_T(...) YLOG_T(Logger, TLOG_ERR, __VA_ARGS__) +#define YLOG_WARNING_T(...) YLOG_T(Logger, TLOG_WARNING, __VA_ARGS__) +#define YLOG_NOTICE_T(...) YLOG_T(Logger, TLOG_NOTICE, __VA_ARGS__) +#define YLOG_INFO_T(...) YLOG_T(Logger, TLOG_INFO, __VA_ARGS__) +#define YLOG_DEBUG_T(...) YLOG_T(Logger, TLOG_DEBUG, __VA_ARGS__) +#define YLOG_RESOURCES_T(...) YLOG_T(Logger, TLOG_RESOURCES , __VA_ARGS__) + namespace NUnifiedAgent { + // Helper functions to format messages + template <typename T> + decltype(auto) YLogFormatMessage(T&& msg) { + return std::forward<T>(msg); + } + + // Overload for multiple arguments (with formatting) + template <typename... Args> + std::string YLogFormatMessage(std::format_string<Args...> fmt, Args&&... args) { + return std::format(fmt, std::forward<Args>(args)...); + } + class TScopeLogger; class TLogger { public: - TLogger(TLog& log, TFMaybe<size_t> rateLimitBytes); + // These counters must outlive the TLogger instance + struct TCounters { + NMonitoring::TDeprecatedCounter* Errors; + NMonitoring::TDeprecatedCounter* DroppedBytes; + NMonitoring::TDeprecatedCounter* RecordsReceived; + NMonitoring::TDeprecatedCounter* RecordsDropped; + }; + + // Throttling state for a single log location + struct TThrottleState { + std::atomic<ui32> TimeSlot{0}; + std::atomic<ui32> Logged{0}; + std::atomic<ui32> Dropped{0}; + }; + + TLogger(TLog& log, TFMaybe<size_t> rateLimitBytes, TCounters counters = {}); + + TLogger(TLog& log, TFMaybe<size_t> rateLimitBytes, ui32 maxLogsPerSlot, ui32 slotSeconds, TCounters counters = {}); + + virtual ~TLogger() = default; void AddLog(TLog& log); @@ -61,26 +120,22 @@ namespace NUnifiedAgent { void FinishTracing() noexcept; - inline TScopeLogger Child(const TString& v, NMonitoring::TDeprecatedCounter* errors = nullptr); - - inline void SetErrorsCounter(NMonitoring::TDeprecatedCounter* counter) noexcept { - Errors = counter; - } - - inline void SetDroppedBytesCounter(NMonitoring::TDeprecatedCounter* counter) noexcept { - DroppedBytes = counter; - } + TScopeLogger Child(const TString& v, NMonitoring::TDeprecatedCounter* errors = nullptr); - inline bool HasRateLimit() const noexcept { - return Throttler != nullptr; + bool HasRateLimit() const noexcept { + return Throttler_ != nullptr; } friend class TScopeLogger; - private: - void Log(TLog& log, ELogPriority logPriority, const TStringBuf message, const TString& scope) const; + protected: + // Accept with throttling support + // Returns: pair of (TLog* if should log or nullptr if dropped, number of previously suppressed logs) + std::pair<TLog*, ui32> Accept(ELogPriority logPriority, NMonitoring::TDeprecatedCounter* errors, TThrottleState& state) const; - inline TLog* Accept(ELogPriority logPriority, NMonitoring::TDeprecatedCounter* errors) const noexcept { + virtual void Log(TLog& log, ELogPriority logPriority, const TStringBuf message, const TString& scope) const; + + TLog* Accept(ELogPriority logPriority, NMonitoring::TDeprecatedCounter* errors) const noexcept { if ((logPriority <= TLOG_ERR) && (errors != nullptr)) { ++(*errors); } @@ -103,8 +158,8 @@ namespace NUnifiedAgent { bool TryConsume(double tokens); private: - TThrottler Throttler; - TAdaptiveLock Lock; + TThrottler Throttler_; + TAdaptiveLock Lock_; }; private: @@ -115,43 +170,47 @@ namespace NUnifiedAgent { void SetTracing(TLogContext& logContext, const char* action); private: - TLogContext DefaultLogContext; - TVector<THolder<TLogContext>> TracingLogContexts; + TLogContext DefaultLogContext_; + TVector<THolder<TLogContext>> TracingLogContexts_; std::atomic<TLogContext*> CurrentLogContext_; - NMonitoring::TDeprecatedCounter* Errors; - NMonitoring::TDeprecatedCounter* DroppedBytes; - const THolder<TThrottlerWithLock> Throttler; - TAdaptiveLock Lock; - TVector<TLog> AdditionalLogs; + TCounters Counters_; + const ui32 MaxLogsPerSlot_; + const ui32 SlotSeconds_; + const THolder<TThrottlerWithLock> Throttler_; + TAdaptiveLock Lock_; + TVector<TLog> AdditionalLogs_; }; class TScopeLogger { public: TScopeLogger(); - inline void Log(TLog& log, ELogPriority logPriority, const TStringBuf message) const { - if (Logger) { - Logger->Log(log, logPriority, message, Scope); + void Log(TLog& log, ELogPriority logPriority, const TStringBuf message) const { + if (Logger_) { + Logger_->Log(log, logPriority, message, Scope_); } } - inline TLog* Accept(ELogPriority logPriority, bool silent) const noexcept { - return Logger ? Logger->Accept(logPriority, silent ? nullptr : Errors) : nullptr; + TLog* Accept(ELogPriority logPriority, bool silent) const noexcept { + return Logger_ ? Logger_->Accept(logPriority, silent ? nullptr : Errors_) : nullptr; } - inline TScopeLogger Child(const TString& v, NMonitoring::TDeprecatedCounter* errors = nullptr) { - return Logger - ? Logger->Child(Join('/', Scope, v), errors == nullptr ? Errors : errors) - : TScopeLogger(); + // Accept with throttling support + std::pair<TLog*, ui32> Accept(ELogPriority logPriority, bool silent, TLogger::TThrottleState& state) const { + return Logger_ + ? Logger_->Accept(logPriority, silent ? nullptr : Errors_, state) + : std::make_pair(nullptr, 0); } - inline TLogger* Unwrap() noexcept { - return Logger; + TScopeLogger Child(const TString& v, NMonitoring::TDeprecatedCounter* errors = nullptr); + + TLogger* Unwrap() noexcept { + return Logger_; } ELogPriority FiltrationLevel() const { - if (Logger) { - return Logger->CurrentLogContext_.load()->Priority; + if (Logger_) { + return Logger_->CurrentLogContext_.load()->Priority; } return LOG_DEF_PRIORITY; } @@ -159,22 +218,12 @@ namespace NUnifiedAgent { friend class TLogger; private: - TScopeLogger(TLogger* logger, - const TString& scope, - NMonitoring::TDeprecatedCounter* errors); + TScopeLogger(TLogger* logger, TString scope, NMonitoring::TDeprecatedCounter* errors); private: - TLogger* Logger; - TString Scope; - NMonitoring::TDeprecatedCounter* Errors; + TLogger* Logger_; + TString Scope_; + NMonitoring::TDeprecatedCounter* Errors_; }; - inline TScopeLogger TLogger::Child(const TString& v, NMonitoring::TDeprecatedCounter* errors) { - return TScopeLogger(this, v, errors == nullptr ? Errors : errors); - } - - inline ELogPriority ToLogPriority(int level) noexcept { - const auto result = ClampVal(level, 0, static_cast<int>(TLOG_RESOURCES)); - return static_cast<ELogPriority>(result); - } -} +} // namespace NUnifiedAgent diff --git a/library/cpp/unified_agent_client/ut/logger_ut.cpp b/library/cpp/unified_agent_client/ut/logger_ut.cpp new file mode 100644 index 00000000000..561c41cb05d --- /dev/null +++ b/library/cpp/unified_agent_client/ut/logger_ut.cpp @@ -0,0 +1,149 @@ +#include <library/cpp/unified_agent_client/logger.h> + +#include <library/cpp/logger/log.h> +#include <library/cpp/logger/stream.h> +#include <library/cpp/monlib/dynamic_counters/counters.h> +#include <library/cpp/testing/gtest/gtest.h> + +#include <sstream> +#include <thread> + +using namespace NUnifiedAgent; +using namespace NMonitoring; + +// Helper to capture log output +class TTestLogBackend : public TLogBackend { +public: + explicit TTestLogBackend(std::ostringstream* stream) + : Stream(stream) + { + } + + void WriteData(const TLogRecord& rec) override { + (*Stream) << rec.Data; + } + + void ReopenLog() override { + } + +private: + std::ostringstream* Stream; +}; + +class TLoggerTest : public ::testing::Test { +protected: + void SetUp() override { + LogStream = std::make_unique<std::ostringstream>(); + Log = std::make_unique<TLog>(MakeHolder<TTestLogBackend>(LogStream.get())); + + // Create counters for testing + Counters = MakeIntrusive<TDynamicCounters>(); + ReceivedCounter = Counters->GetCounter("ReceivedCounter", true).Get(); + DroppedCounter = Counters->GetCounter("DroppedCounter", true).Get(); + + // Create logger with throttling: 20 logs per 1 second + LoggerImpl = std::make_unique<TLogger>(*Log, Nothing(), 20, 1, + TLogger::TCounters{.RecordsReceived = ReceivedCounter, + .RecordsDropped = DroppedCounter}); + Logger = LoggerImpl->Child(""); + } + + std::string GetLogOutput() { + return LogStream->str(); + } + + void ClearLogOutput() { + LogStream->str(""); + LogStream->clear(); + } + + std::unique_ptr<std::ostringstream> LogStream; + std::unique_ptr<TLog> Log; + std::unique_ptr<TLogger> LoggerImpl; + TScopeLogger Logger; + TIntrusivePtr<TDynamicCounters> Counters; + TDeprecatedCounter* ReceivedCounter; + TDeprecatedCounter* DroppedCounter; +}; + +TEST_F(TLoggerTest, BasicThrottling) { + // Log 40 messages using YLOG_T macro + for (int i = 0; i < 40; ++i) { + YLOG_ERROR_T("Test message {}", i); + } + + const auto output = GetLogOutput(); + const int count = std::count(output.begin(), output.end(), '\n'); + + // Should log exactly 20 messages (first slot) + EXPECT_EQ(count, 20); + + // Check counters: 40 received, 20 dropped + EXPECT_EQ(ReceivedCounter->Val(), 40); + EXPECT_EQ(DroppedCounter->Val(), 20); +} + +TEST_F(TLoggerTest, SuppressedCounter) { + for (int i = 20 + 13; i >= 0; --i) { + if (i == 0) { + std::this_thread::sleep_for(std::chrono::seconds(1)); + } + YLOG_ERROR_T("Test message"); + } + + const auto output = GetLogOutput(); + + // Should log 20 messages in first slot + 1 in second slot with suppressed count + const int count = std::count(output.begin(), output.end(), '\n'); + EXPECT_EQ(count, 21); + + // Should contain "suppressed" in the output (from the message after sleep) + EXPECT_NE(output.find("[+13 suppressed]"), std::string::npos); + + // Check counters: 34 received (33 + 1 after sleep), 13 dropped + EXPECT_EQ(ReceivedCounter->Val(), 34); + EXPECT_EQ(DroppedCounter->Val(), 13); +} + +TEST_F(TLoggerTest, IndependentThrottlingPerLocation) { + // Each log location should have independent throttling + for (int i = 0; i < 40; ++i) { + YLOG_ERROR_T("Location A"); // Line 1 + YLOG_ERROR_T("Location B"); // Line 2 - different location + } + + const auto output = GetLogOutput(); + + // Both locations should log ~20 messages each + const int locACount = std::count(output.begin(), output.end(), 'A'); + const int locBCount = std::count(output.begin(), output.end(), 'B'); + + EXPECT_EQ(locACount, 20); + EXPECT_EQ(locBCount, 20); + + // Total counters: 80 received, 40 dropped + EXPECT_EQ(ReceivedCounter->Val(), 80); + EXPECT_EQ(DroppedCounter->Val(), 40); +} + +TEST_F(TLoggerTest, FormatMessage) { + YLOG_ERROR_T("Simple message"); + YLOG_ERROR_T("Formatted: {}, {}", 42, "test"); + + const auto output = GetLogOutput(); + + EXPECT_NE(output.find("Simple message"), std::string::npos); + EXPECT_NE(output.find("Formatted: 42, test"), std::string::npos); +} + +TEST_F(TLoggerTest, DifferentLogLevels) { + YLOG_INFO_T("Info message"); + YLOG_WARNING_T("Warning message"); + YLOG_ERROR_T("Error message"); + + const auto output = GetLogOutput(); + + EXPECT_NE(output.find("Info message"), std::string::npos); + EXPECT_NE(output.find("Warning message"), std::string::npos); + EXPECT_NE(output.find("Error message"), std::string::npos); +} diff --git a/library/cpp/unified_agent_client/ut/ya.make b/library/cpp/unified_agent_client/ut/ya.make new file mode 100644 index 00000000000..62b91b02f60 --- /dev/null +++ b/library/cpp/unified_agent_client/ut/ya.make @@ -0,0 +1,12 @@ +GTEST() + +SRCS( + logger_ut.cpp +) + +PEERDIR( + library/cpp/unified_agent_client + library/cpp/testing/gtest +) + +END() diff --git a/library/cpp/unified_agent_client/ya.make b/library/cpp/unified_agent_client/ya.make index eadd9e94364..ad8323762e9 100644 --- a/library/cpp/unified_agent_client/ya.make +++ b/library/cpp/unified_agent_client/ya.make @@ -36,4 +36,5 @@ END() RECURSE( examples + ut ) |
