diff options
| author | vvvv <[email protected]> | 2025-10-06 11:26:09 +0300 |
|---|---|---|
| committer | vvvv <[email protected]> | 2025-10-06 11:53:26 +0300 |
| commit | 60f45e69a4d7dbc6131208e16c45faf35aa5a985 (patch) | |
| tree | 4daa45b52c295a178c7620e4c93921465fcf7950 /yql/essentials/utils/log | |
| parent | 1bded1a65a7e6e9171418f3e1c691d390125b64e (diff) | |
YQL-20086 utils
init
commit_hash:54feccd520ebd0ab23612bc0cb830914dff9d0e8
Diffstat (limited to 'yql/essentials/utils/log')
| -rw-r--r-- | yql/essentials/utils/log/context.cpp | 42 | ||||
| -rw-r--r-- | yql/essentials/utils/log/context.h | 41 | ||||
| -rw-r--r-- | yql/essentials/utils/log/format.cpp | 258 | ||||
| -rw-r--r-- | yql/essentials/utils/log/format.h | 8 | ||||
| -rw-r--r-- | yql/essentials/utils/log/fwd_backend.cpp | 64 | ||||
| -rw-r--r-- | yql/essentials/utils/log/fwd_backend.h | 32 | ||||
| -rw-r--r-- | yql/essentials/utils/log/log.cpp | 174 | ||||
| -rw-r--r-- | yql/essentials/utils/log/log.h | 63 | ||||
| -rw-r--r-- | yql/essentials/utils/log/log_component.h | 217 | ||||
| -rw-r--r-- | yql/essentials/utils/log/log_level.h | 91 | ||||
| -rw-r--r-- | yql/essentials/utils/log/log_ut.cpp | 1184 | ||||
| -rw-r--r-- | yql/essentials/utils/log/profile.cpp | 12 | ||||
| -rw-r--r-- | yql/essentials/utils/log/profile.h | 34 | ||||
| -rw-r--r-- | yql/essentials/utils/log/tls_backend.cpp | 13 | ||||
| -rw-r--r-- | yql/essentials/utils/log/tls_backend.h | 5 | ||||
| -rw-r--r-- | yql/essentials/utils/log/tls_backend_ut.cpp | 115 | ||||
| -rw-r--r-- | yql/essentials/utils/log/ut/log_parser.cpp | 114 | ||||
| -rw-r--r-- | yql/essentials/utils/log/ut/log_parser.h | 4 | ||||
| -rw-r--r-- | yql/essentials/utils/log/ut/ya.make | 2 | ||||
| -rw-r--r-- | yql/essentials/utils/log/ya.make | 2 |
20 files changed, 1312 insertions, 1163 deletions
diff --git a/yql/essentials/utils/log/context.cpp b/yql/essentials/utils/log/context.cpp index 6f4cb0c580e..fb7db9a5548 100644 --- a/yql/essentials/utils/log/context.cpp +++ b/yql/essentials/utils/log/context.cpp @@ -3,7 +3,6 @@ #include <util/thread/singleton.h> - namespace NYql { namespace NLog { namespace { @@ -12,28 +11,28 @@ struct TThrowedLogContext { TString LocationWithLogContext; // separated with ': ' }; -} // namspace +} // namespace TStringBuf ToStringBuf(EContextKey key) { switch (key) { - case EContextKey::DateTime: - return "datetime"; - case EContextKey::Level: - return "level"; - case EContextKey::ProcessName: - return "procname"; - case EContextKey::ProcessID: - return "pid"; - case EContextKey::ThreadID: - return "tid"; - case EContextKey::Component: - return "component"; - case EContextKey::FileName: - return "filename"; - case EContextKey::Line: - return "line"; - case EContextKey::Path: - return "path"; + case EContextKey::DateTime: + return "datetime"; + case EContextKey::Level: + return "level"; + case EContextKey::ProcessName: + return "procname"; + case EContextKey::ProcessID: + return "pid"; + case EContextKey::ThreadID: + return "tid"; + case EContextKey::Component: + return "component"; + case EContextKey::FileName: + return "filename"; + case EContextKey::Line: + return "line"; + case EContextKey::Path: + return "path"; } } @@ -50,7 +49,7 @@ void OutputLogCtx(IOutputStream* out, bool withBraces, bool skipSessionId) { bool isFirst = true; while (ctxItem != ctxList) { - for (const TString& name: *ctxItem) { + for (const TString& name : *ctxItem) { if (!skipSessionId && !name.empty()) { if (!isFirst) { (*out) << '/'; @@ -92,7 +91,6 @@ TString ThrowedLogContextPath() { return std::move(tlc->LocationWithLogContext); } - TAutoPtr<TLogElement> TContextPreprocessor::Preprocess(TAutoPtr<TLogElement> element) { TStringStream out; diff --git a/yql/essentials/utils/log/context.h b/yql/essentials/utils/log/context.h index f2b423cf494..b8bbb63e9e1 100644 --- a/yql/essentials/utils/log/context.h +++ b/yql/essentials/utils/log/context.h @@ -9,32 +9,34 @@ // continues existing contexts chain -#define YQL_LOG_CTX_SCOPE(...) \ +#define YQL_LOG_CTX_SCOPE(...) \ auto Y_CAT(c, __LINE__) = ::NYql::NLog::MakeCtx(__VA_ARGS__); \ Y_UNUSED(Y_CAT(c, __LINE__)) -#define YQL_LOG_CTX_BLOCK(...) \ +#define YQL_LOG_CTX_BLOCK(...) \ if (auto Y_GENERATE_UNIQUE_ID(c) = ::NYql::NLog::MakeCtx(__VA_ARGS__)) { \ - goto Y_CAT(YQL_LOG_CTX_LABEL, __LINE__); \ - } else Y_CAT(YQL_LOG_CTX_LABEL, __LINE__): - + goto Y_CAT(YQL_LOG_CTX_LABEL, __LINE__); \ + } else \ + Y_CAT(YQL_LOG_CTX_LABEL, __LINE__) \ + : // starts new contexts chain, after leaving current scope restores // previous contexts chain -#define YQL_LOG_CTX_ROOT_SESSION_SCOPE(sessionId, ...) \ +#define YQL_LOG_CTX_ROOT_SESSION_SCOPE(sessionId, ...) \ auto Y_CAT(c, __LINE__) = ::NYql::NLog::MakeRootCtx(sessionId, ##__VA_ARGS__); \ Y_UNUSED(Y_CAT(c, __LINE__)) -#define YQL_LOG_CTX_ROOT_SCOPE(...) \ +#define YQL_LOG_CTX_ROOT_SCOPE(...) \ auto Y_CAT(c, __LINE__) = ::NYql::NLog::MakeRootCtx("", __VA_ARGS__); \ Y_UNUSED(Y_CAT(c, __LINE__)) -#define YQL_LOG_CTX_ROOT_BLOCK(...) \ +#define YQL_LOG_CTX_ROOT_BLOCK(...) \ if (auto Y_GENERATE_UNIQUE_ID(c) = ::NYql::NLog::MakeRootCtx(__VA_ARGS__)) { \ - goto Y_CAT(YQL_LOG_CTX_LABEL, __LINE__); \ - } else Y_CAT(YQL_LOG_CTX_LABEL, __LINE__): - + goto Y_CAT(YQL_LOG_CTX_LABEL, __LINE__); \ + } else \ + Y_CAT(YQL_LOG_CTX_LABEL, __LINE__) \ + : // adds current contexts path to exception message before throwing it @@ -93,7 +95,9 @@ public: } void Unlink() { - if (!HasNext()) return; + if (!HasNext()) { + return; + } Prev->Next = Next; Next->Prev = Prev; @@ -112,11 +116,12 @@ TLogContextListItem* GetLogContextList(); /** * @brief Context element with stored SessionId. -*/ -class TLogContextSessionItem : public TLogContextListItem { + */ +class TLogContextSessionItem: public TLogContextListItem { public: TLogContextSessionItem(size_t size, bool hasSessionId_) - : TLogContextListItem(size, sizeof(*this)) { + : TLogContextListItem(size, sizeof(*this)) + { HasSessionId_ = hasSessionId_; } @@ -128,7 +133,7 @@ private: bool HasSessionId_; }; -} // namspace NImpl +} // namespace NImpl enum class EContextKey { DateTime = 0, @@ -153,7 +158,7 @@ public: template <typename... TArgs> TLogContext(TArgs... args) : TLogContextListItem(Size) - , Names_{{ TString{std::forward<TArgs>(args)}... }} + , Names_{{TString{std::forward<TArgs>(args)}...}} { LinkBefore(NImpl::GetLogContextList()); } @@ -180,7 +185,7 @@ public: template <typename... TArgs> TRootLogContext(const TString& sessionId, TArgs... args) : TLogContextSessionItem(Size, !sessionId.empty()) - , Names_{{ sessionId, TString{std::forward<TArgs>(args)}... }} + , Names_{{sessionId, TString{std::forward<TArgs>(args)}...}} { NImpl::TLogContextListItem* ctxList = NImpl::GetLogContextList(); PrevLogContextHead_.Prev = ctxList->Prev; diff --git a/yql/essentials/utils/log/format.cpp b/yql/essentials/utils/log/format.cpp index 6292235d52d..6cd57fe3fda 100644 --- a/yql/essentials/utils/log/format.cpp +++ b/yql/essentials/utils/log/format.cpp @@ -15,160 +15,160 @@ namespace NYql::NLog { - namespace { +namespace { - constexpr size_t MaxRequiredContextKey = static_cast<size_t>(EContextKey::Line); +constexpr size_t MaxRequiredContextKey = static_cast<size_t>(EContextKey::Line); - auto RequiredContextAccessor(const TLogRecord& rec) { - return [&](EContextKey key) -> TStringBuf { - return rec.MetaFlags.at(static_cast<size_t>(key)).second; - }; - } - - auto OptionalContextAccessor(const TLogRecord& rec) { - return [&](TStringBuf key) -> TMaybe<TStringBuf> { - const auto isContextKeyPath = [&](const auto& pair) { - return pair.first == key; - }; +auto RequiredContextAccessor(const TLogRecord& rec) { + return [&](EContextKey key) -> TStringBuf { + return rec.MetaFlags.at(static_cast<size_t>(key)).second; + }; +} - const auto* path = FindIfPtr( - rec.MetaFlags.begin() + MaxRequiredContextKey + 1, - rec.MetaFlags.end(), - isContextKeyPath); +auto OptionalContextAccessor(const TLogRecord& rec) { + return [&](TStringBuf key) -> TMaybe<TStringBuf> { + const auto isContextKeyPath = [&](const auto& pair) { + return pair.first == key; + }; - if (!path) { - return Nothing(); - } + const auto* path = FindIfPtr( + rec.MetaFlags.begin() + MaxRequiredContextKey + 1, + rec.MetaFlags.end(), + isContextKeyPath); - return path->second; - }; + if (!path) { + return Nothing(); } - void PrintBody(TStringBuilder& out, const TLogRecord& rec, size_t flagBegin) { - out << TStringBuf(rec.Data, rec.Len); + return path->second; + }; +} - if (flagBegin < rec.MetaFlags.size()) { - out << ". Extra context: "; - } +void PrintBody(TStringBuilder& out, const TLogRecord& rec, size_t flagBegin) { + out << TStringBuf(rec.Data, rec.Len); - for (size_t i = flagBegin; i < rec.MetaFlags.size(); ++i) { - const auto& [key, value] = rec.MetaFlags[i]; - out << key << " = " << value; - if (i + 1 != rec.MetaFlags.size()) { - out << ", "; - } - } - } + if (flagBegin < rec.MetaFlags.size()) { + out << ". Extra context: "; + } - TString FallbackFormat(const TLogRecord& rec) { - TStringBuilder out; - PrintBody(out, rec, /*flagBegin=*/0); - return out; + for (size_t i = flagBegin; i < rec.MetaFlags.size(); ++i) { + const auto& [key, value] = rec.MetaFlags[i]; + out << key << " = " << value; + if (i + 1 != rec.MetaFlags.size()) { + out << ", "; } + } +} + +TString FallbackFormat(const TLogRecord& rec) { + TStringBuilder out; + PrintBody(out, rec, /*flagBegin=*/0); + return out; +} + +class TFormattingLogBackend final: public TForwardingLogBackend { +public: + explicit TFormattingLogBackend(TFormatter formatter, bool isStrict, TAutoPtr<TLogBackend> child) + : TForwardingLogBackend(std::move(child)) + , Formatter_(std::move(formatter)) + , IsStrict_(isStrict) + { + } - class TFormattingLogBackend final: public TForwardingLogBackend { - public: - explicit TFormattingLogBackend(TFormatter formatter, bool isStrict, TAutoPtr<TLogBackend> child) - : TForwardingLogBackend(std::move(child)) - , Formatter_(std::move(formatter)) - , IsStrict_(isStrict) - { - } - - void WriteData(const TLogRecord& rec) final { - if (rec.MetaFlags.empty()) { - // NB. For signal handler. - return TForwardingLogBackend::WriteData(rec); - } - - TString message; - if (IsSupported(rec.MetaFlags)) { - message = Formatter_(rec); - } else if (IsStrict_) { - TStringBuilder message; - message << "LogRecord is not supported: "; - PrintBody(message, rec, /* flagBegin = */ 0); - ythrow yexception() << std::move(message); - } else { - message = FallbackFormat(rec); - } - message.append('\n'); - - const TLogRecord formatted(rec.Priority, message.data(), message.size()); - return TForwardingLogBackend::WriteData(formatted); - } + void WriteData(const TLogRecord& rec) final { + if (rec.MetaFlags.empty()) { + // NB. For signal handler. + return TForwardingLogBackend::WriteData(rec); + } - protected: - static bool IsSupported(const TLogRecord::TMetaFlags& flags) { - const auto isSupported = [&](size_t i) -> bool { - const EContextKey key = static_cast<EContextKey>(i); + TString message; + if (IsSupported(rec.MetaFlags)) { + message = Formatter_(rec); + } else if (IsStrict_) { + TStringBuilder message; + message << "LogRecord is not supported: "; + PrintBody(message, rec, /* flagBegin = */ 0); + ythrow yexception() << std::move(message); + } else { + message = FallbackFormat(rec); + } + message.append('\n'); - const TStringBuf expected = ToStringBuf(key); - if (flags.size() <= i) { - return false; - } + const TLogRecord formatted(rec.Priority, message.data(), message.size()); + return TForwardingLogBackend::WriteData(formatted); + } - const TStringBuf actual = flags[i].first; - if (actual != expected) { - return false; - } +protected: + static bool IsSupported(const TLogRecord::TMetaFlags& flags) { + const auto isSupported = [&](size_t i) -> bool { + const EContextKey key = static_cast<EContextKey>(i); - return true; - }; + const TStringBuf expected = ToStringBuf(key); + if (flags.size() <= i) { + return false; + } - return AllOf(std::views::iota(Min<size_t>(), MaxRequiredContextKey), isSupported); + const TStringBuf actual = flags[i].first; + if (actual != expected) { + return false; } - private: - TFormatter Formatter_; - bool IsStrict_; + return true; }; - } // namespace - - TString LegacyFormat(const TLogRecord& rec) { - const auto get = RequiredContextAccessor(rec); - const auto opt = OptionalContextAccessor(rec); - - TStringBuilder out; - out << get(EContextKey::DateTime) << ' ' - << get(EContextKey::Level) << ' ' - << get(EContextKey::ProcessName) - << "(pid=" << get(EContextKey::ProcessID) - << ", tid=" << get(EContextKey::ThreadID) - << ") [" << get(EContextKey::Component) << "] " - << get(EContextKey::FileName) - << ':' << get(EContextKey::Line) << ": "; - - size_t unknownContextBegin = MaxRequiredContextKey + 1; - if (auto path = opt(ToStringBuf(EContextKey::Path))) { - out << "{" << *path << "} "; - unknownContextBegin += 1; - } - - PrintBody(out, rec, unknownContextBegin); - return out; + return AllOf(std::views::iota(Min<size_t>(), MaxRequiredContextKey), isSupported); } - TString JsonFormat(const TLogRecord& rec) { - TStringStream out; - NJsonWriter::TBuf buf(NJsonWriter::HEM_DONT_ESCAPE_HTML, &out); - buf.BeginObject(); - buf.WriteKey("message"); - buf.WriteString(TStringBuf(rec.Data, rec.Len)); - buf.WriteKey("@fields"); - buf.BeginObject(); - for (const auto& [key, value] : rec.MetaFlags) { - buf.WriteKey(key); - buf.WriteString(value); - } - buf.EndObject(); - buf.EndObject(); - return std::move(out.Str()); +private: + TFormatter Formatter_; + bool IsStrict_; +}; + +} // namespace + +TString LegacyFormat(const TLogRecord& rec) { + const auto get = RequiredContextAccessor(rec); + const auto opt = OptionalContextAccessor(rec); + + TStringBuilder out; + out << get(EContextKey::DateTime) << ' ' + << get(EContextKey::Level) << ' ' + << get(EContextKey::ProcessName) + << "(pid=" << get(EContextKey::ProcessID) + << ", tid=" << get(EContextKey::ThreadID) + << ") [" << get(EContextKey::Component) << "] " + << get(EContextKey::FileName) + << ':' << get(EContextKey::Line) << ": "; + + size_t unknownContextBegin = MaxRequiredContextKey + 1; + if (auto path = opt(ToStringBuf(EContextKey::Path))) { + out << "{" << *path << "} "; + unknownContextBegin += 1; } - TAutoPtr<TLogBackend> MakeFormattingLogBackend(TFormatter formatter, bool isStrict, TAutoPtr<TLogBackend> child) { - return new TFormattingLogBackend(std::move(formatter), isStrict, std::move(child)); + PrintBody(out, rec, unknownContextBegin); + return out; +} + +TString JsonFormat(const TLogRecord& rec) { + TStringStream out; + NJsonWriter::TBuf buf(NJsonWriter::HEM_DONT_ESCAPE_HTML, &out); + buf.BeginObject(); + buf.WriteKey("message"); + buf.WriteString(TStringBuf(rec.Data, rec.Len)); + buf.WriteKey("@fields"); + buf.BeginObject(); + for (const auto& [key, value] : rec.MetaFlags) { + buf.WriteKey(key); + buf.WriteString(value); } + buf.EndObject(); + buf.EndObject(); + return std::move(out.Str()); +} + +TAutoPtr<TLogBackend> MakeFormattingLogBackend(TFormatter formatter, bool isStrict, TAutoPtr<TLogBackend> child) { + return new TFormattingLogBackend(std::move(formatter), isStrict, std::move(child)); +} } // namespace NYql::NLog diff --git a/yql/essentials/utils/log/format.h b/yql/essentials/utils/log/format.h index c0ece9412ba..3f4b9b01c0e 100644 --- a/yql/essentials/utils/log/format.h +++ b/yql/essentials/utils/log/format.h @@ -6,12 +6,12 @@ namespace NYql::NLog { - using TFormatter = std::function<TString(const TLogRecord&)>; +using TFormatter = std::function<TString(const TLogRecord&)>; - TString LegacyFormat(const TLogRecord& rec); +TString LegacyFormat(const TLogRecord& rec); - TString JsonFormat(const TLogRecord& rec); +TString JsonFormat(const TLogRecord& rec); - TAutoPtr<TLogBackend> MakeFormattingLogBackend(TFormatter formatter, bool isStrict, TAutoPtr<TLogBackend> child); +TAutoPtr<TLogBackend> MakeFormattingLogBackend(TFormatter formatter, bool isStrict, TAutoPtr<TLogBackend> child); } // namespace NYql::NLog diff --git a/yql/essentials/utils/log/fwd_backend.cpp b/yql/essentials/utils/log/fwd_backend.cpp index 091b07c78f1..be4ce454e54 100644 --- a/yql/essentials/utils/log/fwd_backend.cpp +++ b/yql/essentials/utils/log/fwd_backend.cpp @@ -2,37 +2,37 @@ namespace NYql::NLog { - TForwardingLogBackend::TForwardingLogBackend(TAutoPtr<TLogBackend> child) - : Child_(std::move(child)) - { - } - - void TForwardingLogBackend::WriteData(const TLogRecord& rec) { - return Child_->WriteData(rec); - } - - void TForwardingLogBackend::ReopenLog() { - return Child_->ReopenLog(); - } - - void TForwardingLogBackend::ReopenLogNoFlush() { - return Child_->ReopenLogNoFlush(); - } - - ELogPriority TForwardingLogBackend::FiltrationLevel() const { - return Child_->FiltrationLevel(); - } - - size_t TForwardingLogBackend::QueueSize() const { - return Child_->QueueSize(); - } - - void TForwardingLogBackend::SetChild(TAutoPtr<TLogBackend> child) { - Child_ = std::move(child); - } - - TAutoPtr<TLogBackend> TForwardingLogBackend::GetChild() const { - return Child_; - } +TForwardingLogBackend::TForwardingLogBackend(TAutoPtr<TLogBackend> child) + : Child_(std::move(child)) +{ +} + +void TForwardingLogBackend::WriteData(const TLogRecord& rec) { + return Child_->WriteData(rec); +} + +void TForwardingLogBackend::ReopenLog() { + return Child_->ReopenLog(); +} + +void TForwardingLogBackend::ReopenLogNoFlush() { + return Child_->ReopenLogNoFlush(); +} + +ELogPriority TForwardingLogBackend::FiltrationLevel() const { + return Child_->FiltrationLevel(); +} + +size_t TForwardingLogBackend::QueueSize() const { + return Child_->QueueSize(); +} + +void TForwardingLogBackend::SetChild(TAutoPtr<TLogBackend> child) { + Child_ = std::move(child); +} + +TAutoPtr<TLogBackend> TForwardingLogBackend::GetChild() const { + return Child_; +} } // namespace NYql::NLog diff --git a/yql/essentials/utils/log/fwd_backend.h b/yql/essentials/utils/log/fwd_backend.h index 144d2eccee2..21fcd3dc32f 100644 --- a/yql/essentials/utils/log/fwd_backend.h +++ b/yql/essentials/utils/log/fwd_backend.h @@ -6,21 +6,21 @@ namespace NYql::NLog { - class TForwardingLogBackend: public TLogBackend { - public: - explicit TForwardingLogBackend(TAutoPtr<TLogBackend> child); - - void WriteData(const TLogRecord& rec) override; - void ReopenLog() override; - void ReopenLogNoFlush() override; - ELogPriority FiltrationLevel() const override; - size_t QueueSize() const override; - - void SetChild(TAutoPtr<TLogBackend> child); - TAutoPtr<TLogBackend> GetChild() const; - - private: - TAutoPtr<TLogBackend> Child_; - }; +class TForwardingLogBackend: public TLogBackend { +public: + explicit TForwardingLogBackend(TAutoPtr<TLogBackend> child); + + void WriteData(const TLogRecord& rec) override; + void ReopenLog() override; + void ReopenLogNoFlush() override; + ELogPriority FiltrationLevel() const override; + size_t QueueSize() const override; + + void SetChild(TAutoPtr<TLogBackend> child); + TAutoPtr<TLogBackend> GetChild() const; + +private: + TAutoPtr<TLogBackend> Child_; +}; } // namespace NYql::NLog diff --git a/yql/essentials/utils/log/log.cpp b/yql/essentials/utils/log/log.cpp index 1b03c194b6a..73394c4f2de 100644 --- a/yql/essentials/utils/log/log.cpp +++ b/yql/essentials/utils/log/log.cpp @@ -25,10 +25,9 @@ static TMutex g_InitLoggerMutex; static int g_LoggerInitialized = 0; - namespace { -class TLimitedLogBackend final : public TLogBackend { +class TLimitedLogBackend final: public TLogBackend { public: TLimitedLogBackend(TAutoPtr<TLogBackend> b, TAtomic& flag, ui64 limit) noexcept : Backend_(b) @@ -97,7 +96,6 @@ private: char Buf_[1 << 20]; char* Current_; char* const End_; - }; TEmergencyLogOutput EMERGENCY_LOG_OUT; @@ -106,82 +104,119 @@ void LogBacktraceOnSignal(int signum) { if (NYql::NLog::IsYqlLoggerInitialized()) { EMERGENCY_LOG_OUT << #ifdef _win_ - signum + signum #else - strsignal(signum) + strsignal(signum) #endif - << TStringBuf(" (pid=") << GetPID() << TStringBuf("): "); + << TStringBuf(" (pid=") << GetPID() << TStringBuf("): "); NYql::NBacktrace::KikimrBackTraceFormatImpl(&EMERGENCY_LOG_OUT); EMERGENCY_LOG_OUT.Flush(); } } - // Conversions between NYql::NProto::TLoggingConfig enums and NYql::NLog enums NYql::NLog::ELevel ConvertLevel(NYql::NProto::TLoggingConfig::ELevel level) { using namespace NYql::NProto; using namespace NYql::NLog; switch (level) { - case TLoggingConfig::FATAL: return ELevel::FATAL; - case TLoggingConfig::ERROR: return ELevel::ERROR; - case TLoggingConfig::WARN: return ELevel::WARN; - case TLoggingConfig::INFO: return ELevel::INFO; - case TLoggingConfig::DEBUG: return ELevel::DEBUG; - case TLoggingConfig::TRACE: return ELevel::TRACE; + case TLoggingConfig::FATAL: + return ELevel::FATAL; + case TLoggingConfig::ERROR: + return ELevel::ERROR; + case TLoggingConfig::WARN: + return ELevel::WARN; + case TLoggingConfig::INFO: + return ELevel::INFO; + case TLoggingConfig::DEBUG: + return ELevel::DEBUG; + case TLoggingConfig::TRACE: + return ELevel::TRACE; } ythrow yexception() << "unknown log level: " - << TLoggingConfig::ELevel_Name(level); + << TLoggingConfig::ELevel_Name(level); } NYql::NLog::EComponent ConvertComponent(NYql::NProto::TLoggingConfig::EComponent c) { using namespace NYql::NProto; using namespace NYql::NLog; switch (c) { - case TLoggingConfig::DEFAULT: return EComponent::Default; - case TLoggingConfig::CORE: return EComponent::Core; - case TLoggingConfig::CORE_EVAL: return EComponent::CoreEval; - case TLoggingConfig::CORE_PEEPHOLE: return EComponent::CorePeepHole; - case TLoggingConfig::CORE_EXECUTION: return EComponent::CoreExecution; - case TLoggingConfig::SQL: return EComponent::Sql; - case TLoggingConfig::PROVIDER_COMMON: return EComponent::ProviderCommon; - case TLoggingConfig::PROVIDER_CONFIG: return EComponent::ProviderConfig; - case TLoggingConfig::PROVIDER_RESULT: return EComponent::ProviderResult; - case TLoggingConfig::PROVIDER_YT: return EComponent::ProviderYt; - case TLoggingConfig::PROVIDER_KIKIMR: return EComponent::ProviderKikimr; - case TLoggingConfig::PROVIDER_KQP: return EComponent::ProviderKqp; - case TLoggingConfig::PROVIDER_RTMR: return EComponent::ProviderRtmr; - case TLoggingConfig::PERFORMANCE: return EComponent::Perf; - case TLoggingConfig::NET: return EComponent::Net; - case TLoggingConfig::PROVIDER_STAT: return EComponent::ProviderStat; - case TLoggingConfig::PROVIDER_SOLOMON: return EComponent::ProviderSolomon; - case TLoggingConfig::PROVIDER_DQ: return EComponent::ProviderDq; - case TLoggingConfig::PROVIDER_CLICKHOUSE: return EComponent::ProviderClickHouse; - case TLoggingConfig::PROVIDER_YDB: return EComponent::ProviderYdb; - case TLoggingConfig::PROVIDER_PQ: return EComponent::ProviderPq; - case TLoggingConfig::PROVIDER_S3: return EComponent::ProviderS3; - case TLoggingConfig::CORE_DQ: return EComponent::CoreDq; - case TLoggingConfig::HTTP_GATEWAY: return EComponent::HttpGateway; - case TLoggingConfig::PROVIDER_GENERIC: return EComponent::ProviderGeneric; - case TLoggingConfig::PROVIDER_PG: return EComponent::ProviderPg; - case TLoggingConfig::PROVIDER_PURE: return EComponent::ProviderPure; - case TLoggingConfig::FAST_MAP_REDUCE: return EComponent::FastMapReduce; - case TLoggingConfig::PROVIDER_YTFLOW: return EComponent::ProviderYtflow; + case TLoggingConfig::DEFAULT: + return EComponent::Default; + case TLoggingConfig::CORE: + return EComponent::Core; + case TLoggingConfig::CORE_EVAL: + return EComponent::CoreEval; + case TLoggingConfig::CORE_PEEPHOLE: + return EComponent::CorePeepHole; + case TLoggingConfig::CORE_EXECUTION: + return EComponent::CoreExecution; + case TLoggingConfig::SQL: + return EComponent::Sql; + case TLoggingConfig::PROVIDER_COMMON: + return EComponent::ProviderCommon; + case TLoggingConfig::PROVIDER_CONFIG: + return EComponent::ProviderConfig; + case TLoggingConfig::PROVIDER_RESULT: + return EComponent::ProviderResult; + case TLoggingConfig::PROVIDER_YT: + return EComponent::ProviderYt; + case TLoggingConfig::PROVIDER_KIKIMR: + return EComponent::ProviderKikimr; + case TLoggingConfig::PROVIDER_KQP: + return EComponent::ProviderKqp; + case TLoggingConfig::PROVIDER_RTMR: + return EComponent::ProviderRtmr; + case TLoggingConfig::PERFORMANCE: + return EComponent::Perf; + case TLoggingConfig::NET: + return EComponent::Net; + case TLoggingConfig::PROVIDER_STAT: + return EComponent::ProviderStat; + case TLoggingConfig::PROVIDER_SOLOMON: + return EComponent::ProviderSolomon; + case TLoggingConfig::PROVIDER_DQ: + return EComponent::ProviderDq; + case TLoggingConfig::PROVIDER_CLICKHOUSE: + return EComponent::ProviderClickHouse; + case TLoggingConfig::PROVIDER_YDB: + return EComponent::ProviderYdb; + case TLoggingConfig::PROVIDER_PQ: + return EComponent::ProviderPq; + case TLoggingConfig::PROVIDER_S3: + return EComponent::ProviderS3; + case TLoggingConfig::CORE_DQ: + return EComponent::CoreDq; + case TLoggingConfig::HTTP_GATEWAY: + return EComponent::HttpGateway; + case TLoggingConfig::PROVIDER_GENERIC: + return EComponent::ProviderGeneric; + case TLoggingConfig::PROVIDER_PG: + return EComponent::ProviderPg; + case TLoggingConfig::PROVIDER_PURE: + return EComponent::ProviderPure; + case TLoggingConfig::FAST_MAP_REDUCE: + return EComponent::FastMapReduce; + case TLoggingConfig::PROVIDER_YTFLOW: + return EComponent::ProviderYtflow; } ythrow yexception() << "unknown log component: " - << TLoggingConfig::EComponent_Name(c); + << TLoggingConfig::EComponent_Name(c); } TString ConvertDestinationType(NYql::NProto::TLoggingConfig::ELogTo c) { switch (c) { - case NYql::NProto::TLoggingConfig::STDOUT: return "cout"; - case NYql::NProto::TLoggingConfig::STDERR: return "cerr"; - case NYql::NProto::TLoggingConfig::CONSOLE: return "console"; - default : { - ythrow yexception() << "unsupported ELogTo destination in Convert"; - } + case NYql::NProto::TLoggingConfig::STDOUT: + return "cout"; + case NYql::NProto::TLoggingConfig::STDERR: + return "cerr"; + case NYql::NProto::TLoggingConfig::CONSOLE: + return "console"; + default: { + ythrow yexception() << "unsupported ELogTo destination in Convert"; + } } ythrow yexception() << "unknown ELogTo destination"; @@ -204,16 +239,16 @@ NYql::NProto::TLoggingConfig::TLogDestination CreateLogDestination(const TString NYql::NLog::TFormatter Formatter(const NYql::NProto::TLoggingConfig& config) { switch (config.GetFormat().Format_case()) { - case NYql::NProto::TLoggingConfig_TFormat::kLegacyFormat: - return NYql::NLog::LegacyFormat; - case NYql::NProto::TLoggingConfig_TFormat::kJsonFormat: - return NYql::NLog::JsonFormat; - case NYql::NProto::TLoggingConfig_TFormat::FORMAT_NOT_SET: - return NYql::NLog::LegacyFormat; + case NYql::NProto::TLoggingConfig_TFormat::kLegacyFormat: + return NYql::NLog::LegacyFormat; + case NYql::NProto::TLoggingConfig_TFormat::kJsonFormat: + return NYql::NLog::JsonFormat; + case NYql::NProto::TLoggingConfig_TFormat::FORMAT_NOT_SET: + return NYql::NLog::LegacyFormat; } } -} // namspace +} // namespace namespace NYql { namespace NLog { @@ -234,7 +269,7 @@ TString GetLocalTime() { return std::move(time.Str()); } -} +} // namespace NImpl void WriteLocalTime(IOutputStream* out) { struct timeval now; @@ -255,7 +290,9 @@ TYqlLog::TYqlLog() : TLog() , ProcName_() , ProcId_() - , WriteTruncMsg_(0) {} + , WriteTruncMsg_(0) +{ +} TYqlLog::TYqlLog(const TString& logType, const TComponentLevels& levels) : TLog(logType) @@ -285,9 +322,8 @@ void TYqlLog::UpdateProcInfo(const TString& procName) { } TAutoPtr<TLogElement> TYqlLog::CreateLogElement( - EComponent component, ELevel level, - TStringBuf file, int line) const -{ + EComponent component, ELevel level, + TStringBuf file, int line) const { if (/* const bool writeMsg = */ AtomicCas(&WriteTruncMsg_, 0, 1)) { TLogElement fatal(this, ELevelHelpers::ToLogPriority(ELevel::FATAL)); Contextify(fatal, EComponent::Default, ELevel::FATAL, __FILE__, __LINE__); @@ -336,7 +372,7 @@ void InitLogger(const TString& logType, bool startAsDaemon) { } void InitLogger(const NProto::TLoggingConfig& config, bool startAsDaemon) { - with_lock(g_InitLoggerMutex) { + with_lock (g_InitLoggerMutex) { ++g_LoggerInitialized; if (g_LoggerInitialized > 1) { return; @@ -349,7 +385,7 @@ void InitLogger(const NProto::TLoggingConfig& config, bool startAsDaemon) { levels.fill(ELevel::INFO); } - for (const auto& cmpLevel: config.GetLevels()) { + for (const auto& cmpLevel : config.GetLevels()) { auto component = ConvertComponent(cmpLevel.GetC()); auto level = ConvertLevel(cmpLevel.GetL()); levels[EComponentHelpers::ToInt(component)] = level; @@ -410,11 +446,11 @@ void InitLogger(const NProto::TLoggingConfig& config, bool startAsDaemon) { config.GetFormat().GetIsStrict(), std::move(backend))); } - NYql::NBacktrace::AddAfterFatalCallback([](int signo){ LogBacktraceOnSignal(signo); }); + NYql::NBacktrace::AddAfterFatalCallback([](int signo) { LogBacktraceOnSignal(signo); }); } void InitLogger(TAutoPtr<TLogBackend> backend, TFormatter formatter, bool isStrictFormatting) { - with_lock(g_InitLoggerMutex) { + with_lock (g_InitLoggerMutex) { ++g_LoggerInitialized; if (g_LoggerInitialized > 1) { return; @@ -426,7 +462,7 @@ void InitLogger(TAutoPtr<TLogBackend> backend, TFormatter formatter, bool isStri levels.fill(ELevel::INFO); TLoggerOperator<TYqlLog>::Set(new TYqlLog(backend, levels)); } - NYql::NBacktrace::AddAfterFatalCallback([](int signo){ LogBacktraceOnSignal(signo); }); + NYql::NBacktrace::AddAfterFatalCallback([](int signo) { LogBacktraceOnSignal(signo); }); } void InitLogger(IOutputStream* out, TFormatter formatter, bool isStrictFormatting) { @@ -434,7 +470,7 @@ void InitLogger(IOutputStream* out, TFormatter formatter, bool isStrictFormattin } void CleanupLogger() { - with_lock(g_InitLoggerMutex) { + with_lock (g_InitLoggerMutex) { --g_LoggerInitialized; if (g_LoggerInitialized > 0) { return; @@ -445,7 +481,7 @@ void CleanupLogger() { } void ReopenLog() { - with_lock(g_InitLoggerMutex) { + with_lock (g_InitLoggerMutex) { TLoggerOperator<TYqlLog>::Log().ReopenLog(); } } diff --git a/yql/essentials/utils/log/log.h b/yql/essentials/utils/log/log.h index 68aa8b09b0e..e531c183104 100644 --- a/yql/essentials/utils/log/log.h +++ b/yql/essentials/utils/log/log.h @@ -14,45 +14,43 @@ #include <array> - -#define YQL_LOG_IMPL(logger, component, level, preprocessor, file, line) \ +#define YQL_LOG_IMPL(logger, component, level, preprocessor, file, line) \ logger.NeedToLog(component, level) && NPrivateGlobalLogger::TEatStream() | \ - (*preprocessor::Preprocess(logger.CreateLogElement(component, level, file, line))) + (*preprocessor::Preprocess(logger.CreateLogElement(component, level, file, line))) #define YQL_LOG_IF_IMPL(logger, component, level, preprocessor, condition, file, line) \ - logger.NeedToLog(component, level) && (condition) && NPrivateGlobalLogger::TEatStream() | \ - (*preprocessor::Preprocess(logger.CreateLogElement(component, level, file, line))) + logger.NeedToLog(component, level) && (condition) && NPrivateGlobalLogger::TEatStream() | (*preprocessor::Preprocess(logger.CreateLogElement(component, level, file, line))) // with component logger -#define YQL_CLOG_PREP(level, component, preprocessor) YQL_LOG_IMPL(\ - ::NYql::NLog::YqlLogger(), \ - ::NYql::NLog::EComponent::component, \ - ::NYql::NLog::ELevel::level, \ - preprocessor, \ +#define YQL_CLOG_PREP(level, component, preprocessor) YQL_LOG_IMPL( \ + ::NYql::NLog::YqlLogger(), \ + ::NYql::NLog::EComponent::component, \ + ::NYql::NLog::ELevel::level, \ + preprocessor, \ __FILE__, __LINE__) #define YQL_CLOG(level, component) \ YQL_CLOG_PREP(level, component, ::NYql::NLog::TContextPreprocessor) #define YQL_CLOG_ACTIVE(level, component) ::NYql::NLog::YqlLogger().NeedToLog( \ - ::NYql::NLog::EComponent::component, \ + ::NYql::NLog::EComponent::component, \ ::NYql::NLog::ELevel::level) // with component/level values logger -#define YQL_CVLOG_PREP(level, component, preprocessor) YQL_LOG_IMPL(\ - ::NYql::NLog::YqlLogger(), \ - component, \ - level, \ - preprocessor, \ +#define YQL_CVLOG_PREP(level, component, preprocessor) YQL_LOG_IMPL( \ + ::NYql::NLog::YqlLogger(), \ + component, \ + level, \ + preprocessor, \ __FILE__, __LINE__) #define YQL_CVLOG(level, component) \ YQL_CVLOG_PREP(level, component, ::NYql::NLog::TContextPreprocessor) #define YQL_CVLOG_ACTIVE(level, component) ::NYql::NLog::YqlLogger().NeedToLog( \ - component, \ + component, \ level) // default logger @@ -67,12 +65,12 @@ // conditional logger -#define YQL_CLOG_PREP_IF(level, component, preprocessor, condition) YQL_LOG_IF_IMPL(\ - ::NYql::NLog::YqlLogger(), \ - ::NYql::NLog::EComponent::component, \ - ::NYql::NLog::ELevel::level, \ - preprocessor, \ - condition, \ +#define YQL_CLOG_PREP_IF(level, component, preprocessor, condition) YQL_LOG_IF_IMPL( \ + ::NYql::NLog::YqlLogger(), \ + ::NYql::NLog::EComponent::component, \ + ::NYql::NLog::ELevel::level, \ + preprocessor, \ + condition, \ __FILE__, __LINE__) #define YQL_CLOG_IF(level, component, condition) \ @@ -84,12 +82,11 @@ #define YQL_LOG_IF(level, condition) \ YQL_LOG_PREP_IF(level, ::NYql::NLog::TContextPreprocessor, condition) - namespace NYql { namespace NProto { - class TLoggingConfig; -} // NProto +class TLoggingConfig; +} // namespace NProto namespace NLog { @@ -99,10 +96,10 @@ TString GetThreadId(); TString GetLocalTime(); -} +} // namespace NImpl using TComponentLevels = - std::array<ELevel, EComponentHelpers::ToInt(EComponent::MaxValue)>; + std::array<ELevel, EComponentHelpers::ToInt(EComponent::MaxValue)>; void WriteLocalTime(IOutputStream* out); @@ -181,7 +178,7 @@ void InitLogger(const TString& log, bool startAsDaemon = false); /** * @brief Initialize logger with backends described in config. -*/ + */ void InitLogger(const NProto::TLoggingConfig& loggingConfig, bool startAsDaemon = false); /** @@ -204,7 +201,9 @@ void ReopenLog(); class YqlLoggerScope { public: - YqlLoggerScope(const TString& log, bool startAsDaemon = false) { InitLogger(log, startAsDaemon); } + YqlLoggerScope(const TString& log, bool startAsDaemon = false) { + InitLogger(log, startAsDaemon); + } YqlLoggerScope(TAutoPtr<TLogBackend> backend, TFormatter formatter = LegacyFormat, bool isStrictFormatting = true) { InitLogger(backend, std::move(formatter), isStrictFormatting); @@ -214,7 +213,9 @@ public: InitLogger(out, std::move(formatter), isStrictFormatting); } - ~YqlLoggerScope() { CleanupLogger(); } + ~YqlLoggerScope() { + CleanupLogger(); + } }; } // namespace NLog diff --git a/yql/essentials/utils/log/log_component.h b/yql/essentials/utils/log/log_component.h index be1df138635..bd284cb9d81 100644 --- a/yql/essentials/utils/log/log_component.h +++ b/yql/essentials/utils/log/log_component.h @@ -3,7 +3,6 @@ #include <util/generic/strbuf.h> #include <util/generic/yexception.h> - namespace NYql { namespace NLog { @@ -20,7 +19,8 @@ enum class EComponent { ProviderKikimr, ProviderKqp, ProviderRtmr, - Performance, Perf = Performance, + Performance, + Perf = Performance, Net, ProviderStat, ProviderSolomon, @@ -50,77 +50,164 @@ struct EComponentHelpers { static constexpr EComponent FromInt(int component) { return (component >= ToInt(EComponent::Default) && component < ToInt(EComponent::MaxValue)) - ? static_cast<EComponent>(component) - : EComponent::Default; + ? static_cast<EComponent>(component) + : EComponent::Default; } static TStringBuf ToString(EComponent component) { switch (component) { - case EComponent::Default: return TStringBuf("default"); - case EComponent::Core: return TStringBuf("core"); - case EComponent::CoreEval: return TStringBuf("core eval"); - case EComponent::CorePeepHole: return TStringBuf("core peephole"); - case EComponent::CoreExecution: return TStringBuf("core exec"); - case EComponent::Sql: return TStringBuf("sql"); - case EComponent::ProviderCommon: return TStringBuf("common provider"); - case EComponent::ProviderConfig: return TStringBuf("CONFIG"); - case EComponent::ProviderResult: return TStringBuf("RESULT"); - case EComponent::ProviderYt: return TStringBuf("YT"); - case EComponent::ProviderKikimr: return TStringBuf("KIKIMR"); - case EComponent::ProviderKqp: return TStringBuf("KQP"); - case EComponent::ProviderRtmr: return TStringBuf("RTMR"); - case EComponent::Performance: return TStringBuf("perf"); - case EComponent::Net: return TStringBuf("net"); - case EComponent::ProviderStat: return TStringBuf("STATFACE"); - case EComponent::ProviderSolomon: return TStringBuf("SOLOMON"); - case EComponent::ProviderDq: return TStringBuf("DQ"); - case EComponent::ProviderClickHouse: return TStringBuf("CLICKHOUSE"); - case EComponent::ProviderYdb: return TStringBuf("YDB"); - case EComponent::ProviderPq: return TStringBuf("PQ"); - case EComponent::ProviderS3: return TStringBuf("S3"); - case EComponent::CoreDq: return TStringBuf("core dq"); - case EComponent::HttpGateway: return TStringBuf("http gw"); - case EComponent::ProviderGeneric: return TStringBuf("generic"); - case EComponent::ProviderPg: return TStringBuf("PG"); - case EComponent::ProviderPure: return TStringBuf("pure"); - case EComponent::FastMapReduce: return TStringBuf("FMR"); - case EComponent::ProviderYtflow: return TStringBuf("YTFLOW"); - default: - ythrow yexception() << "invalid log component value: " - << ToInt(component); + case EComponent::Default: + return TStringBuf("default"); + case EComponent::Core: + return TStringBuf("core"); + case EComponent::CoreEval: + return TStringBuf("core eval"); + case EComponent::CorePeepHole: + return TStringBuf("core peephole"); + case EComponent::CoreExecution: + return TStringBuf("core exec"); + case EComponent::Sql: + return TStringBuf("sql"); + case EComponent::ProviderCommon: + return TStringBuf("common provider"); + case EComponent::ProviderConfig: + return TStringBuf("CONFIG"); + case EComponent::ProviderResult: + return TStringBuf("RESULT"); + case EComponent::ProviderYt: + return TStringBuf("YT"); + case EComponent::ProviderKikimr: + return TStringBuf("KIKIMR"); + case EComponent::ProviderKqp: + return TStringBuf("KQP"); + case EComponent::ProviderRtmr: + return TStringBuf("RTMR"); + case EComponent::Performance: + return TStringBuf("perf"); + case EComponent::Net: + return TStringBuf("net"); + case EComponent::ProviderStat: + return TStringBuf("STATFACE"); + case EComponent::ProviderSolomon: + return TStringBuf("SOLOMON"); + case EComponent::ProviderDq: + return TStringBuf("DQ"); + case EComponent::ProviderClickHouse: + return TStringBuf("CLICKHOUSE"); + case EComponent::ProviderYdb: + return TStringBuf("YDB"); + case EComponent::ProviderPq: + return TStringBuf("PQ"); + case EComponent::ProviderS3: + return TStringBuf("S3"); + case EComponent::CoreDq: + return TStringBuf("core dq"); + case EComponent::HttpGateway: + return TStringBuf("http gw"); + case EComponent::ProviderGeneric: + return TStringBuf("generic"); + case EComponent::ProviderPg: + return TStringBuf("PG"); + case EComponent::ProviderPure: + return TStringBuf("pure"); + case EComponent::FastMapReduce: + return TStringBuf("FMR"); + case EComponent::ProviderYtflow: + return TStringBuf("YTFLOW"); + default: + ythrow yexception() << "invalid log component value: " + << ToInt(component); } } static EComponent FromString(TStringBuf str) { - if (str == TStringBuf("default")) return EComponent::Default; - if (str == TStringBuf("core")) return EComponent::Core; - if (str == TStringBuf("core eval")) return EComponent::CoreEval; - if (str == TStringBuf("core peephole")) return EComponent::CorePeepHole; - if (str == TStringBuf("core exec")) return EComponent::CoreExecution; - if (str == TStringBuf("sql")) return EComponent::Sql; - if (str == TStringBuf("common provider")) return EComponent::ProviderCommon; - if (str == TStringBuf("CONFIG")) return EComponent::ProviderConfig; - if (str == TStringBuf("RESULT")) return EComponent::ProviderResult; - if (str == TStringBuf("YT")) return EComponent::ProviderYt; - if (str == TStringBuf("KIKIMR")) return EComponent::ProviderKikimr; - if (str == TStringBuf("KQP")) return EComponent::ProviderKqp; - if (str == TStringBuf("RTMR")) return EComponent::ProviderRtmr; - if (str == TStringBuf("perf")) return EComponent::Performance; - if (str == TStringBuf("net")) return EComponent::Net; - if (str == TStringBuf("STATFACE")) return EComponent::ProviderStat; - if (str == TStringBuf("SOLOMON")) return EComponent::ProviderSolomon; - if (str == TStringBuf("DQ")) return EComponent::ProviderDq; - if (str == TStringBuf("CLICKHOUSE")) return EComponent::ProviderClickHouse; - if (str == TStringBuf("YDB")) return EComponent::ProviderYdb; - if (str == TStringBuf("PQ")) return EComponent::ProviderPq; - if (str == TStringBuf("S3")) return EComponent::ProviderS3; - if (str == TStringBuf("core dq")) return EComponent::CoreDq; - if (str == TStringBuf("http gw")) return EComponent::HttpGateway; - if (str == TStringBuf("generic")) return EComponent::ProviderGeneric; - if (str == TStringBuf("PG")) return EComponent::ProviderPg; - if (str == TStringBuf("pure")) return EComponent::ProviderPure; - if (str == TStringBuf("FMR")) return EComponent::FastMapReduce; - if (str == TStringBuf("YTFLOW")) return EComponent::ProviderYtflow; + if (str == TStringBuf("default")) { + return EComponent::Default; + } + if (str == TStringBuf("core")) { + return EComponent::Core; + } + if (str == TStringBuf("core eval")) { + return EComponent::CoreEval; + } + if (str == TStringBuf("core peephole")) { + return EComponent::CorePeepHole; + } + if (str == TStringBuf("core exec")) { + return EComponent::CoreExecution; + } + if (str == TStringBuf("sql")) { + return EComponent::Sql; + } + if (str == TStringBuf("common provider")) { + return EComponent::ProviderCommon; + } + if (str == TStringBuf("CONFIG")) { + return EComponent::ProviderConfig; + } + if (str == TStringBuf("RESULT")) { + return EComponent::ProviderResult; + } + if (str == TStringBuf("YT")) { + return EComponent::ProviderYt; + } + if (str == TStringBuf("KIKIMR")) { + return EComponent::ProviderKikimr; + } + if (str == TStringBuf("KQP")) { + return EComponent::ProviderKqp; + } + if (str == TStringBuf("RTMR")) { + return EComponent::ProviderRtmr; + } + if (str == TStringBuf("perf")) { + return EComponent::Performance; + } + if (str == TStringBuf("net")) { + return EComponent::Net; + } + if (str == TStringBuf("STATFACE")) { + return EComponent::ProviderStat; + } + if (str == TStringBuf("SOLOMON")) { + return EComponent::ProviderSolomon; + } + if (str == TStringBuf("DQ")) { + return EComponent::ProviderDq; + } + if (str == TStringBuf("CLICKHOUSE")) { + return EComponent::ProviderClickHouse; + } + if (str == TStringBuf("YDB")) { + return EComponent::ProviderYdb; + } + if (str == TStringBuf("PQ")) { + return EComponent::ProviderPq; + } + if (str == TStringBuf("S3")) { + return EComponent::ProviderS3; + } + if (str == TStringBuf("core dq")) { + return EComponent::CoreDq; + } + if (str == TStringBuf("http gw")) { + return EComponent::HttpGateway; + } + if (str == TStringBuf("generic")) { + return EComponent::ProviderGeneric; + } + if (str == TStringBuf("PG")) { + return EComponent::ProviderPg; + } + if (str == TStringBuf("pure")) { + return EComponent::ProviderPure; + } + if (str == TStringBuf("FMR")) { + return EComponent::FastMapReduce; + } + if (str == TStringBuf("YTFLOW")) { + return EComponent::ProviderYtflow; + } ythrow yexception() << "unknown log component: '" << str << '\''; } diff --git a/yql/essentials/utils/log/log_level.h b/yql/essentials/utils/log/log_level.h index ccb12e4690b..5471e411d52 100644 --- a/yql/essentials/utils/log/log_level.h +++ b/yql/essentials/utils/log/log_level.h @@ -5,7 +5,6 @@ #include <util/generic/strbuf.h> #include <util/generic/yexception.h> - namespace NYql { namespace NLog { @@ -38,47 +37,74 @@ struct ELevelHelpers { static ELevel FromInt(int level) { switch (level) { - case TLOG_EMERG: - case TLOG_ALERT: - case TLOG_CRIT: return ELevel::FATAL; - - case TLOG_ERR: return ELevel::ERROR; - case TLOG_WARNING: return ELevel::WARN; - - case TLOG_NOTICE: - case TLOG_INFO: return ELevel::INFO; - - case TLOG_DEBUG: return ELevel::DEBUG; - case TLOG_RESOURCES: return ELevel::TRACE; - - default: - return ELevel::INFO; + case TLOG_EMERG: + case TLOG_ALERT: + case TLOG_CRIT: + return ELevel::FATAL; + + case TLOG_ERR: + return ELevel::ERROR; + case TLOG_WARNING: + return ELevel::WARN; + + case TLOG_NOTICE: + case TLOG_INFO: + return ELevel::INFO; + + case TLOG_DEBUG: + return ELevel::DEBUG; + case TLOG_RESOURCES: + return ELevel::TRACE; + + default: + return ELevel::INFO; } } static TStringBuf ToString(ELevel level) { // aligned 5-letters string switch (level) { - case ELevel::FATAL: return TStringBuf("FATAL"); - case ELevel::ERROR: return TStringBuf("ERROR"); - case ELevel::WARN: return TStringBuf("WARN "); - case ELevel::NOTICE:return TStringBuf("NOTE "); - case ELevel::INFO: return TStringBuf("INFO "); - case ELevel::DEBUG: return TStringBuf("DEBUG"); - case ELevel::TRACE: return TStringBuf("TRACE"); + case ELevel::FATAL: + return TStringBuf("FATAL"); + case ELevel::ERROR: + return TStringBuf("ERROR"); + case ELevel::WARN: + return TStringBuf("WARN "); + case ELevel::NOTICE: + return TStringBuf("NOTE "); + case ELevel::INFO: + return TStringBuf("INFO "); + case ELevel::DEBUG: + return TStringBuf("DEBUG"); + case ELevel::TRACE: + return TStringBuf("TRACE"); } ythrow yexception() << "unknown log level: " << ToInt(level); } static ELevel FromString(TStringBuf str) { // aligned 5-letters string - if (str == TStringBuf("FATAL")) return ELevel::FATAL; - if (str == TStringBuf("ERROR")) return ELevel::ERROR; - if (str == TStringBuf("WARN ")) return ELevel::WARN; - if (str == TStringBuf("NOTE ")) return ELevel::NOTICE; - if (str == TStringBuf("INFO ")) return ELevel::INFO; - if (str == TStringBuf("DEBUG")) return ELevel::DEBUG; - if (str == TStringBuf("TRACE")) return ELevel::TRACE; + if (str == TStringBuf("FATAL")) { + return ELevel::FATAL; + } + if (str == TStringBuf("ERROR")) { + return ELevel::ERROR; + } + if (str == TStringBuf("WARN ")) { + return ELevel::WARN; + } + if (str == TStringBuf("NOTE ")) { + return ELevel::NOTICE; + } + if (str == TStringBuf("INFO ")) { + return ELevel::INFO; + } + if (str == TStringBuf("DEBUG")) { + return ELevel::DEBUG; + } + if (str == TStringBuf("TRACE")) { + return ELevel::TRACE; + } ythrow yexception() << "unknown log level: " << str; } @@ -93,6 +119,5 @@ struct ELevelHelpers { } }; - -} // namspace NLog -} // namspace NYql +} // namespace NLog +} // namespace NYql diff --git a/yql/essentials/utils/log/log_ut.cpp b/yql/essentials/utils/log/log_ut.cpp index e2ad8b24824..32cb5c9c02e 100644 --- a/yql/essentials/utils/log/log_ut.cpp +++ b/yql/essentials/utils/log/log_ut.cpp @@ -18,710 +18,708 @@ #include <regex> - using namespace NYql; using namespace NLog; Y_UNIT_TEST_SUITE(TLogTest) { - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(WrittingWithoutMacro) { - TStringStream out; - YqlLoggerScope logger(&out, Format, /* isStrict */ false); - - TString message = "some performance info"; - YqlLogger().Write(ELogPriority::TLOG_INFO, message); - - TString logRow = out.Str(); - UNIT_ASSERT_STRING_CONTAINS(logRow, message); - } +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(WrittingWithoutMacro) { + TStringStream out; + YqlLoggerScope logger(&out, Format, /* isStrict */ false); - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(WrittingUnknownMetaFlag) { - TStringStream out; - YqlLoggerScope logger(&out, Format, /* isStrict */ false); + TString message = "some performance info"; + YqlLogger().Write(ELogPriority::TLOG_INFO, message); - TString message = "some performance info"; - YqlLogger().Write(ELogPriority::TLOG_INFO, message, {{"unknown", "value"}}); + TString logRow = out.Str(); + UNIT_ASSERT_STRING_CONTAINS(logRow, message); +} - TString logRow = out.Str(); - UNIT_ASSERT_STRING_CONTAINS(logRow, message); - UNIT_ASSERT_STRING_CONTAINS(logRow, "unknown = value"); - } +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(WrittingUnknownMetaFlag) { + TStringStream out; + YqlLoggerScope logger(&out, Format, /* isStrict */ false); - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Formatting) { - TStringStream out; - YqlLoggerScope logger(&out, Format); - YqlLogger().UpdateProcInfo("my_proc"); + TString message = "some performance info"; + YqlLogger().Write(ELogPriority::TLOG_INFO, message, {{"unknown", "value"}}); - TString message = "some performance info"; - YQL_LOG(INFO) << message; + TString logRow = out.Str(); + UNIT_ASSERT_STRING_CONTAINS(logRow, message); + UNIT_ASSERT_STRING_CONTAINS(logRow, "unknown = value"); +} - TLogRow logRow = ParseLogRow(out.Str()); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Formatting) { + TStringStream out; + YqlLoggerScope logger(&out, Format); + YqlLogger().UpdateProcInfo("my_proc"); + + TString message = "some performance info"; + YQL_LOG(INFO) << message; + + TLogRow logRow = ParseLogRow(out.Str()); + + TDuration elapsed(logRow.Time - TInstant::Now()); + UNIT_ASSERT(elapsed < TDuration::MilliSeconds(5)); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_STRINGS_EQUAL(logRow.ProcName, "my_proc"); + UNIT_ASSERT_EQUAL(logRow.ProcId, GetPID()); + UNIT_ASSERT(logRow.ThreadId > 0); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL( + logRow.FileName, + TStringBuf(__FILE__).RNextTok(LOCSLASH_C)); + UNIT_ASSERT(logRow.LineNumber != 0); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, message); +} - TDuration elapsed(logRow.Time - TInstant::Now()); - UNIT_ASSERT(elapsed < TDuration::MilliSeconds(5)); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_STRINGS_EQUAL(logRow.ProcName, "my_proc"); - UNIT_ASSERT_EQUAL(logRow.ProcId, GetPID()); - UNIT_ASSERT(logRow.ThreadId > 0); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL( - logRow.FileName, - TStringBuf(__FILE__).RNextTok(LOCSLASH_C)); - UNIT_ASSERT(logRow.LineNumber != 0); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, message); - } +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(SpecialCharacters) { + TStringStream out; + YqlLoggerScope logger(&out, Format); + YqlLogger().UpdateProcInfo("\\evil\\"); - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(SpecialCharacters) { - TStringStream out; - YqlLoggerScope logger(&out, Format); - YqlLogger().UpdateProcInfo("\\evil\\"); + YQL_LOG(INFO) << "My name is \"YQL\"!"; - YQL_LOG(INFO) << "My name is \"YQL\"!"; + TLogRow logRow = ParseLogRow(out.Str()); + UNIT_ASSERT_STRINGS_EQUAL(logRow.ProcName, "\\evil\\"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "My name is \"YQL\"!"); +} - TLogRow logRow = ParseLogRow(out.Str()); - UNIT_ASSERT_STRINGS_EQUAL(logRow.ProcName, "\\evil\\"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "My name is \"YQL\"!"); - } +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Levels) { + TStringStream out; + YqlLoggerScope logger(&out, Format); // default log level INFO - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Levels) { - TStringStream out; - YqlLoggerScope logger(&out, Format); // default log level INFO + YQL_LOG(FATAL) << "fatal message"; + YQL_LOG(ERROR) << "error message"; + YQL_LOG(WARN) << "warning message"; + YQL_LOG(INFO) << "info message"; + YQL_LOG(DEBUG) << "debug message"; + YQL_LOG(TRACE) << "trace message"; - YQL_LOG(FATAL) << "fatal message"; - YQL_LOG(ERROR) << "error message"; - YQL_LOG(WARN) << "warning message"; - YQL_LOG(INFO) << "info message"; - YQL_LOG(DEBUG) << "debug message"; - YQL_LOG(TRACE) << "trace message"; + TString fatalStr, errorStr, warnStr, infoStr, _; + Split(out.Str(), '\n', fatalStr, errorStr, warnStr, infoStr, _); - TString fatalStr, errorStr, warnStr, infoStr, _; - Split(out.Str(), '\n', fatalStr, errorStr, warnStr, infoStr, _); - - { - TLogRow logRow = ParseLogRow(fatalStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::FATAL); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "fatal message"); - } - { - TLogRow logRow = ParseLogRow(errorStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::ERROR); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "error message"); - } - { - TLogRow logRow = ParseLogRow(warnStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "warning message"); - } - { - TLogRow logRow = ParseLogRow(infoStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "info message"); - } + { + TLogRow logRow = ParseLogRow(fatalStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::FATAL); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "fatal message"); } + { + TLogRow logRow = ParseLogRow(errorStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::ERROR); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "error message"); + } + { + TLogRow logRow = ParseLogRow(warnStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "warning message"); + } + { + TLogRow logRow = ParseLogRow(infoStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "info message"); + } +} - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Components) { - TStringStream out; - YqlLoggerScope logger(&out, Format); - - YQL_CLOG(INFO, Default) << "default message"; - YQL_CLOG(INFO, Core) << "core message"; - YQL_CLOG(INFO, Sql) << "sql message"; - YQL_CLOG(INFO, ProviderCommon) << "common message"; - YQL_CLOG(INFO, ProviderYt) << "yt message"; - YQL_CLOG(INFO, ProviderKikimr) << "kikimr message"; - YQL_CLOG(INFO, ProviderRtmr) << "rtmr message"; - YQL_CLOG(INFO, Performance) << "performance message"; - YQL_CLOG(INFO, Perf) << "perf message"; - - TString defaultStr, coreStr, sqlStr, commonStr, ytStr, - kikimrStr, rtmrStr, performanceStr, perfStr, _; - Split(out.Str(), '\n', defaultStr, coreStr, sqlStr, - commonStr, ytStr, - kikimrStr, rtmrStr, - performanceStr, perfStr, _); - - { - TLogRow logRow = ParseLogRow(defaultStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "default message"); - } - { - TLogRow logRow = ParseLogRow(coreStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "core message"); - } - { - TLogRow logRow = ParseLogRow(sqlStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Sql); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "sql message"); - } - { - TLogRow logRow = ParseLogRow(commonStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderCommon); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "common message"); - } - { - TLogRow logRow = ParseLogRow(ytStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderYt); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "yt message"); - } - { - TLogRow logRow = ParseLogRow(kikimrStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderKikimr); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "kikimr message"); - } - { - TLogRow logRow = ParseLogRow(rtmrStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderRtmr); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "rtmr message"); - } - { - TLogRow logRow = ParseLogRow(performanceStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "performance message"); - } - { - TLogRow logRow = ParseLogRow(perfStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "perf message"); - } +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Components) { + TStringStream out; + YqlLoggerScope logger(&out, Format); + + YQL_CLOG(INFO, Default) << "default message"; + YQL_CLOG(INFO, Core) << "core message"; + YQL_CLOG(INFO, Sql) << "sql message"; + YQL_CLOG(INFO, ProviderCommon) << "common message"; + YQL_CLOG(INFO, ProviderYt) << "yt message"; + YQL_CLOG(INFO, ProviderKikimr) << "kikimr message"; + YQL_CLOG(INFO, ProviderRtmr) << "rtmr message"; + YQL_CLOG(INFO, Performance) << "performance message"; + YQL_CLOG(INFO, Perf) << "perf message"; + + TString defaultStr, coreStr, sqlStr, commonStr, ytStr, + kikimrStr, rtmrStr, performanceStr, perfStr, _; + Split(out.Str(), '\n', defaultStr, coreStr, sqlStr, + commonStr, ytStr, + kikimrStr, rtmrStr, + performanceStr, perfStr, _); + + { + TLogRow logRow = ParseLogRow(defaultStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "default message"); + } + { + TLogRow logRow = ParseLogRow(coreStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "core message"); + } + { + TLogRow logRow = ParseLogRow(sqlStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Sql); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "sql message"); + } + { + TLogRow logRow = ParseLogRow(commonStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderCommon); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "common message"); + } + { + TLogRow logRow = ParseLogRow(ytStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderYt); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "yt message"); + } + { + TLogRow logRow = ParseLogRow(kikimrStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderKikimr); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "kikimr message"); + } + { + TLogRow logRow = ParseLogRow(rtmrStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::ProviderRtmr); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "rtmr message"); + } + { + TLogRow logRow = ParseLogRow(performanceStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "performance message"); + } + { + TLogRow logRow = ParseLogRow(perfStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "perf message"); } +} - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Conditional) { - TStringStream out; - YqlLoggerScope logger(&out, Format); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Conditional) { + TStringStream out; + YqlLoggerScope logger(&out, Format); - YQL_LOG_IF(INFO, true) << "default info message"; - YQL_LOG_IF(INFO, false) << "must not be logged"; + YQL_LOG_IF(INFO, true) << "default info message"; + YQL_LOG_IF(INFO, false) << "must not be logged"; - YQL_CLOG_IF(INFO, Perf, true) << "perf info message"; - YQL_CLOG_IF(INFO, Perf, false) << "perf info message"; + YQL_CLOG_IF(INFO, Perf, true) << "perf info message"; + YQL_CLOG_IF(INFO, Perf, false) << "perf info message"; - TString defaultStr, perfStr, _; - Split(out.Str(), '\n', defaultStr, perfStr, _); + TString defaultStr, perfStr, _; + Split(out.Str(), '\n', defaultStr, perfStr, _); - { - TLogRow logRow = ParseLogRow(defaultStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "default info message"); - } - { - TLogRow logRow = ParseLogRow(perfStr); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "perf info message"); - } + { + TLogRow logRow = ParseLogRow(defaultStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "default info message"); } + { + TLogRow logRow = ParseLogRow(perfStr); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "perf info message"); + } +} - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Contexts) { - TStringStream out; - YqlLoggerScope logger(&out, Format); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Contexts) { + TStringStream out; + YqlLoggerScope logger(&out, Format); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); - YQL_LOG(INFO) << "level0 - begin"; - { - YQL_LOG_CTX_SCOPE("ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); - YQL_LOG(INFO) << "level1 - begin"; + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); + YQL_LOG(INFO) << "level0 - begin"; + { + YQL_LOG_CTX_SCOPE("ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); + YQL_LOG(INFO) << "level1 - begin"; - YQL_LOG_CTX_BLOCK(TStringBuf("ctx2")) { - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1/ctx2"); - YQL_LOG(WARN) << "level2"; - } - - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); - YQL_LOG(INFO) << "level1 - end"; + YQL_LOG_CTX_BLOCK(TStringBuf("ctx2")) { + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1/ctx2"); + YQL_LOG(WARN) << "level2"; } - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); - YQL_LOG(INFO) << "level0 - end"; - TString row1Str, row2Str, row3Str, row4Str, row5Str, _; - Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); + YQL_LOG(INFO) << "level1 - end"; + } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); + YQL_LOG(INFO) << "level0 - end"; - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - begin"); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1/ctx2"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2"); - } - { - TLogRow logRow = ParseLogRow(row4Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); - } - { - TLogRow logRow = ParseLogRow(row5Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - end"); - } + TString row1Str, row2Str, row3Str, row4Str, row5Str, _; + Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); + + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - begin"); } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); + } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1/ctx2"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2"); + } + { + TLogRow logRow = ParseLogRow(row4Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); + } + { + TLogRow logRow = ParseLogRow(row5Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - end"); + } +} - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(UnknownSessionContexts) { - TStringStream out; - YqlLoggerScope logger(&out, Format); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(UnknownSessionContexts) { + TStringStream out; + YqlLoggerScope logger(&out, Format); + + { + YQL_LOG_CTX_ROOT_SCOPE("ctx"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, ""); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); + YQL_LOG(INFO) << "level0 - begin"; { - YQL_LOG_CTX_ROOT_SCOPE("ctx"); + YQL_LOG_CTX_ROOT_SESSION_SCOPE(CurrentLogContextPath()); UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, ""); UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - YQL_LOG(INFO) << "level0 - begin"; - { - YQL_LOG_CTX_ROOT_SESSION_SCOPE(CurrentLogContextPath()); + YQL_LOG(INFO) << "level1 - begin"; + YQL_LOG_CTX_BLOCK("ctx1") { UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, ""); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - - YQL_LOG(INFO) << "level1 - begin"; - YQL_LOG_CTX_BLOCK("ctx1") { - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, ""); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx/ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx/ctx1"); - YQL_LOG(WARN) << "level2"; - } - - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, ""); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - YQL_LOG(INFO) << "level1 - end"; + YQL_LOG(WARN) << "level2"; } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, ""); UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - YQL_LOG(INFO) << "level0 - end"; + YQL_LOG(INFO) << "level1 - end"; } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, ""); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); + YQL_LOG(INFO) << "level0 - end"; + } - TString row1Str, row2Str, row3Str, row4Str, row5Str, _; - Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - begin"); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx/ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2"); - } - { - TLogRow logRow = ParseLogRow(row4Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); - } - { - TLogRow logRow = ParseLogRow(row5Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - end"); - } + TString row1Str, row2Str, row3Str, row4Str, row5Str, _; + Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - begin"); + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); + } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx/ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2"); + } + { + TLogRow logRow = ParseLogRow(row4Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); } + { + TLogRow logRow = ParseLogRow(row5Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - end"); + } +} - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(SessionContexts) { - TStringStream out; - YqlLoggerScope logger(&out, Format); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(SessionContexts) { + TStringStream out; + YqlLoggerScope logger(&out, Format); + + { + YQL_LOG_CTX_ROOT_SESSION_SCOPE("sessionId", "ctx"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, "sessionId"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); + YQL_LOG(INFO) << "level0 - begin"; { - YQL_LOG_CTX_ROOT_SESSION_SCOPE("sessionId", "ctx"); + YQL_LOG_CTX_ROOT_SESSION_SCOPE(CurrentLogContextPath()); UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, "sessionId"); UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - YQL_LOG(INFO) << "level0 - begin"; - { - YQL_LOG_CTX_ROOT_SESSION_SCOPE(CurrentLogContextPath()); + YQL_LOG(INFO) << "level1 - begin"; + YQL_LOG_CTX_BLOCK("ctx1") { UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, "sessionId"); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - - YQL_LOG(INFO) << "level1 - begin"; - YQL_LOG_CTX_BLOCK("ctx1") { - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, "sessionId"); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx/ctx1"); - - YQL_LOG(WARN) << "level2"; - } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx/ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, "sessionId"); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - YQL_LOG(INFO) << "level1 - end"; + YQL_LOG(WARN) << "level2"; } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, "sessionId"); UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); - YQL_LOG(INFO) << "level0 - end"; - } - - TString row1Str, row2Str, row3Str, row4Str, row5Str, _; - Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - begin"); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx/ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2"); - } - { - TLogRow logRow = ParseLogRow(row4Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); - } - { - TLogRow logRow = ParseLogRow(row5Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - end"); + YQL_LOG(INFO) << "level1 - end"; } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().first, "sessionId"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx"); + YQL_LOG(INFO) << "level0 - end"; } - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(ThrowWithContext) { - bool isThrown = false; - YQL_LOG_CTX_SCOPE("first"); - try { - YQL_LOG_CTX_SCOPE("second"); - YQL_LOG_CTX_THROW yexception() << "some message"; - } catch (const yexception& e) { - isThrown = true; - - UNIT_ASSERT_STRINGS_EQUAL(e.AsStrBuf(), "some message"); - - TString throwedLogCtx = ThrowedLogContextPath(); - TStringBuf file, line, context; - TStringBuf(throwedLogCtx).Split(".cpp:", file, line); - line.Split(':', line, context); - - TString expectedFile(__LOCATION__.File); - SubstGlobal(expectedFile, LOCSLASH_C, '/'); - UNIT_ASSERT_STRINGS_EQUAL(TString(file)+".cpp", expectedFile); - int lineNumber; - UNIT_ASSERT(TryFromString<int>(line, lineNumber)); - UNIT_ASSERT(lineNumber > 0); - UNIT_ASSERT_STRINGS_EQUAL(context, " {first/second} "); - - // second call without throw returns empty string - throwedLogCtx = ThrowedLogContextPath(); - UNIT_ASSERT(throwedLogCtx.empty()); - } + TString row1Str, row2Str, row3Str, row4Str, row5Str, _; + Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - begin"); + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); + } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx/ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2"); + } + { + TLogRow logRow = ParseLogRow(row4Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); + } + { + TLogRow logRow = ParseLogRow(row5Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "sessionId/ctx"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level0 - end"); + } +} - UNIT_ASSERT_C(isThrown, "exception was not thrown"); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(ThrowWithContext) { + bool isThrown = false; + YQL_LOG_CTX_SCOPE("first"); + try { + YQL_LOG_CTX_SCOPE("second"); + YQL_LOG_CTX_THROW yexception() << "some message"; + } catch (const yexception& e) { + isThrown = true; + + UNIT_ASSERT_STRINGS_EQUAL(e.AsStrBuf(), "some message"); + + TString throwedLogCtx = ThrowedLogContextPath(); + TStringBuf file, line, context; + TStringBuf(throwedLogCtx).Split(".cpp:", file, line); + line.Split(':', line, context); + + TString expectedFile(__LOCATION__.File); + SubstGlobal(expectedFile, LOCSLASH_C, '/'); + UNIT_ASSERT_STRINGS_EQUAL(TString(file) + ".cpp", expectedFile); + int lineNumber; + UNIT_ASSERT(TryFromString<int>(line, lineNumber)); + UNIT_ASSERT(lineNumber > 0); + UNIT_ASSERT_STRINGS_EQUAL(context, " {first/second} "); + + // second call without throw returns empty string + throwedLogCtx = ThrowedLogContextPath(); + UNIT_ASSERT(throwedLogCtx.empty()); } - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(ContextOverride) { - TStringStream out; - YqlLoggerScope logger(&out, Format); + UNIT_ASSERT_C(isThrown, "exception was not thrown"); +} - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); - { - YQL_LOG_CTX_SCOPE("ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); - YQL_LOG(INFO) << "level1 - begin"; +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(ContextOverride) { + TStringStream out; + YqlLoggerScope logger(&out, Format); - YQL_LOG_CTX_BLOCK(TStringBuf("ctx2")) { - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1/ctx2"); - YQL_LOG(WARN) << "level2 - begin"; + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); + { + YQL_LOG_CTX_SCOPE("ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); + YQL_LOG(INFO) << "level1 - begin"; - { - YQL_LOG_CTX_ROOT_SCOPE("ctx3"); - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx3"); - YQL_LOG(ERROR) << "level3"; - } + YQL_LOG_CTX_BLOCK(TStringBuf("ctx2")) { + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1/ctx2"); + YQL_LOG(WARN) << "level2 - begin"; - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1/ctx2"); - YQL_LOG(WARN) << "level2 - end"; + { + YQL_LOG_CTX_ROOT_SCOPE("ctx3"); + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx3"); + YQL_LOG(ERROR) << "level3"; } - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); - YQL_LOG(INFO) << "level1 - end"; + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1/ctx2"); + YQL_LOG(WARN) << "level2 - end"; } - UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); - - TString row1Str, row2Str, row3Str, row4Str, row5Str, _; - Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1/ctx2"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2 - begin"); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::ERROR); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx3"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level3"); - } - { - TLogRow logRow = ParseLogRow(row4Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1/ctx2"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2 - end"); - } - { - TLogRow logRow = ParseLogRow(row5Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); - } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, "ctx1"); + YQL_LOG(INFO) << "level1 - end"; } + UNIT_ASSERT_STRINGS_EQUAL(CurrentLogContextPath().second, ""); - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Profiling) { - TStringStream out; - YqlLoggerScope logger(&out, Format); + TString row1Str, row2Str, row3Str, row4Str, row5Str, _; + Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, row5Str, _); - { - YQL_PROFILE_SCOPE(INFO, "scope1"); - } + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - begin"); + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1/ctx2"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2 - begin"); + } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::ERROR); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx3"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level3"); + } + { + TLogRow logRow = ParseLogRow(row4Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1/ctx2"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level2 - end"); + } + { + TLogRow logRow = ParseLogRow(row5Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Path, "ctx1"); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "level1 - end"); + } +} - YQL_PROFILE_BLOCK(WARN, "block1") { - Sleep(TDuration::MilliSeconds(2)); - } +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Profiling) { + TStringStream out; + YqlLoggerScope logger(&out, Format); - YQL_PROFILE_BLOCK(ERROR, "block2") { - Sleep(TDuration::MilliSeconds(1200)); - } + { + YQL_PROFILE_SCOPE(INFO, "scope1"); + } - bool isExecuted = false; - YQL_PROFILE_BLOCK(TRACE, "block3") { // log will be filtered out - isExecuted = true; - } - UNIT_ASSERT(isExecuted); + YQL_PROFILE_BLOCK(WARN, "block1") { + Sleep(TDuration::MilliSeconds(2)); + } - TString row1Str, row2Str, row3Str, _; - Split(out.Str(), '\n', row1Str, row2Str, row3Str, _); + YQL_PROFILE_BLOCK(ERROR, "block2") { + Sleep(TDuration::MilliSeconds(1200)); + } - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); - std::regex re("Execution of \\[scope1\\] took [0-9\\.]+us"); - bool isMatch = std::regex_match(logRow.Message.c_str(), re); - UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); - std::regex re("Execution of \\[block1\\] took [0-9\\.]+ms"); - bool isMatch = std::regex_match(logRow.Message.c_str(), re); - UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::ERROR); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); - std::regex re("Execution of \\[block2\\] took [0-9\\.]+s"); - bool isMatch = std::regex_match(logRow.Message.c_str(), re); - UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); - } + bool isExecuted = false; + YQL_PROFILE_BLOCK(TRACE, "block3") { // log will be filtered out + isExecuted = true; } + UNIT_ASSERT(isExecuted); + TString row1Str, row2Str, row3Str, _; + Split(out.Str(), '\n', row1Str, row2Str, row3Str, _); - int Func1(int a, char b) { - YQL_PROFILE_FUNC(INFO); - return a + b; + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); + std::regex re("Execution of \\[scope1\\] took [0-9\\.]+us"); + bool isMatch = std::regex_match(logRow.Message.c_str(), re); + UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); } - - int Func2(int a, char b) { - YQL_PROFILE_FUNCSIG(WARN); - return a + b; + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); + std::regex re("Execution of \\[block1\\] took [0-9\\.]+ms"); + bool isMatch = std::regex_match(logRow.Message.c_str(), re); + UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); + } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::ERROR); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); + std::regex re("Execution of \\[block2\\] took [0-9\\.]+s"); + bool isMatch = std::regex_match(logRow.Message.c_str(), re); + UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); } +} - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(ProfilingFuncs) { - TStringStream out; - YqlLoggerScope logger(&out, Format); +int Func1(int a, char b) { + YQL_PROFILE_FUNC(INFO); + return a + b; +} - Func1(1, 2); - Func2(1, 2); +int Func2(int a, char b) { + YQL_PROFILE_FUNCSIG(WARN); + return a + b; +} - TString row1Str, row2Str, _; - Split(out.Str(), '\n', row1Str, row2Str, _); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(ProfilingFuncs) { + TStringStream out; + YqlLoggerScope logger(&out, Format); - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); + Func1(1, 2); + Func2(1, 2); + + TString row1Str, row2Str, _; + Split(out.Str(), '\n', row1Str, row2Str, _); + + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); #ifdef _win_ - std::regex re("Execution of \\[[NTestSuiteTLogTest::Func1\\] took [0-9\\.]+us"); + std::regex re("Execution of \\[[NTestSuiteTLogTest::Func1\\] took [0-9\\.]+us"); #else - std::regex re("Execution of \\[Func1\\] took [0-9\\.]+us"); + std::regex re("Execution of \\[Func1\\] took [0-9\\.]+us"); #endif - bool isMatch = std::regex_match(logRow.Message.c_str(), re); - UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); + bool isMatch = std::regex_match(logRow.Message.c_str(), re); + UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Perf); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Performance); #ifdef _win_ - std::regex re("Execution of \\[int __cdecl NTestSuiteTLogTest::Func2\\(int, char\\)\\] took [0-9\\.]+us"); + std::regex re("Execution of \\[int __cdecl NTestSuiteTLogTest::Func2\\(int, char\\)\\] took [0-9\\.]+us"); #else - std::regex re("Execution of \\[int NTestSuiteTLogTest::Func2\\(int, char\\)\\] took [0-9\\.]+us"); + std::regex re("Execution of \\[int NTestSuiteTLogTest::Func2\\(int, char\\)\\] took [0-9\\.]+us"); #endif - bool isMatch = std::regex_match(logRow.Message.c_str(), re); - UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); - } + bool isMatch = std::regex_match(logRow.Message.c_str(), re); + UNIT_ASSERT_C(isMatch, "Unexpected message: " << logRow.Message); } +} - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Limit1) { - size_t limit = 0; - { - TStringStream out; - YqlLoggerScope logger(&out, Format); - YqlLogger().UpdateProcInfo("proc"); - YQL_CLOG(INFO, Core) << "message1"; - limit = out.Str().length() * 2 - 7; // Not more than 2 log lines - } - +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Limit1) { + size_t limit = 0; + { TStringStream out; YqlLoggerScope logger(&out, Format); YqlLogger().UpdateProcInfo("proc"); - YqlLogger().SetMaxLogLimit(limit); - YQL_CLOG(INFO, Core) << "message1"; - YQL_CLOG(INFO, Core) << "message2"; - YQL_CLOG(INFO, Core) << "message3"; + limit = out.Str().length() * 2 - 7; // Not more than 2 log lines + } - TString row1Str, row2Str, row3Str, _; - Split(out.Str(), '\n', row1Str, row2Str, row3Str, _); + TStringStream out; + YqlLoggerScope logger(&out, Format); + YqlLogger().UpdateProcInfo("proc"); + YqlLogger().SetMaxLogLimit(limit); - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message1"); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message2"); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::FATAL); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "Log is truncated by limit"); - } - } + YQL_CLOG(INFO, Core) << "message1"; + YQL_CLOG(INFO, Core) << "message2"; + YQL_CLOG(INFO, Core) << "message3"; - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Limit2) { - size_t limit = 0; - { - TStringStream out; - YqlLoggerScope logger(&out, Format); - YqlLogger().UpdateProcInfo("proc"); - YQL_CLOG(INFO, Core) << "message1"; - limit = out.Str().length() * 2 - 7; // Not more than 2 log lines - } + TString row1Str, row2Str, row3Str, _; + Split(out.Str(), '\n', row1Str, row2Str, row3Str, _); + + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message1"); + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message2"); + } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::FATAL); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "Log is truncated by limit"); + } +} +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(Limit2) { + size_t limit = 0; + { TStringStream out; YqlLoggerScope logger(&out, Format); YqlLogger().UpdateProcInfo("proc"); - YqlLogger().SetMaxLogLimit(limit); - YQL_CLOG(INFO, Core) << "message1"; - YQL_CLOG(INFO, Core) << "message2"; - YQL_CLOG(WARN, Core) << "message3"; + limit = out.Str().length() * 2 - 7; // Not more than 2 log lines + } - TString row1Str, row2Str, row3Str, row4Str, _; - Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, _); + TStringStream out; + YqlLoggerScope logger(&out, Format); + YqlLogger().UpdateProcInfo("proc"); + YqlLogger().SetMaxLogLimit(limit); - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message1"); - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message2"); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::FATAL); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "Log is truncated by limit"); - } - { - TLogRow logRow = ParseLogRow(row4Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message3"); - } + YQL_CLOG(INFO, Core) << "message1"; + YQL_CLOG(INFO, Core) << "message2"; + YQL_CLOG(WARN, Core) << "message3"; + + TString row1Str, row2Str, row3Str, row4Str, _; + Split(out.Str(), '\n', row1Str, row2Str, row3Str, row4Str, _); + + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message1"); + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message2"); + } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::FATAL); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "Log is truncated by limit"); + } + { + TLogRow logRow = ParseLogRow(row4Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::WARN); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Core); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "message3"); } } +} // Y_UNIT_TEST_SUITE(TLogTest) diff --git a/yql/essentials/utils/log/profile.cpp b/yql/essentials/utils/log/profile.cpp index 130bb05a4ab..66bf8de7171 100644 --- a/yql/essentials/utils/log/profile.cpp +++ b/yql/essentials/utils/log/profile.cpp @@ -3,12 +3,10 @@ #include <util/stream/format.h> - -#define YQL_PERF_LOG(level, file, line) YQL_LOG_IMPL( \ +#define YQL_PERF_LOG(level, file, line) YQL_LOG_IMPL( \ ::NYql::NLog::YqlLogger(), ::NYql::NLog::EComponent::Perf, level, \ ::NYql::NLog::TContextPreprocessor, file, line) - namespace NYql { namespace NLog { @@ -30,8 +28,8 @@ TProfilingScope::~TProfilingScope() { auto doLog = [&]() { YQL_PERF_LOG(Level_, File_, Line_) - << TStringBuf("Execution of [") << Name_ - << TStringBuf("] took ") << Prec(elapsed, 3) << unit; + << TStringBuf("Execution of [") << Name_ + << TStringBuf("] took ") << Prec(elapsed, 3) << unit; }; if (!LogCtxPath_.first.empty() || !LogCtxPath_.second.empty()) { @@ -46,5 +44,5 @@ TProfilingScope::~TProfilingScope() { } } -} // namspace NLog -} // namspace NYql +} // namespace NLog +} // namespace NYql diff --git a/yql/essentials/utils/log/profile.h b/yql/essentials/utils/log/profile.h index dda7e03f9d2..0c5fd4f74d9 100644 --- a/yql/essentials/utils/log/profile.h +++ b/yql/essentials/utils/log/profile.h @@ -5,29 +5,30 @@ #include <util/system/datetime.h> - -#define YQL_PROFILE_SCOPE(level, name) \ +#define YQL_PROFILE_SCOPE(level, name) \ ::NYql::NLog::TProfilingScope Y_GENERATE_UNIQUE_ID(ps)( \ - name, ::NYql::NLog::ELevel::level, __FILE__, __LINE__) + name, ::NYql::NLog::ELevel::level, __FILE__, __LINE__) #define YQL_PROFILE_BLOCK_IMPL(level, name) \ - ::NYql::NLog::TProfilingScope( \ - name, ::NYql::NLog::ELevel::level, __FILE__, __LINE__) + ::NYql::NLog::TProfilingScope( \ + name, ::NYql::NLog::ELevel::level, __FILE__, __LINE__) -#define YQL_PROFILE_SCOPE_VAL(level, name) \ - TAutoPtr<::NYql::NLog::TProfilingScope>(new ::NYql::NLog::TProfilingScope(\ - name, ::NYql::NLog::ELevel::level, __FILE__, __LINE__, \ - ::NYql::NLog::CurrentLogContextPath())) +#define YQL_PROFILE_SCOPE_VAL(level, name) \ + TAutoPtr<::NYql::NLog::TProfilingScope>(new ::NYql::NLog::TProfilingScope( \ + name, ::NYql::NLog::ELevel::level, __FILE__, __LINE__, \ + ::NYql::NLog::CurrentLogContextPath())) -#define YQL_PROFILE_BIND_VAL(future, scopeVal) \ +#define YQL_PROFILE_BIND_VAL(future, scopeVal) \ future.Apply([scopeVal](const decltype(future)& f) { \ - return f.GetValue(); \ + return f.GetValue(); \ }); -#define YQL_PROFILE_BLOCK(level, name) \ +#define YQL_PROFILE_BLOCK(level, name) \ if (auto Y_GENERATE_UNIQUE_ID(t) = YQL_PROFILE_SCOPE_VAL(level, name)) { \ - goto Y_CAT(YQL_LOG_CTX_LABEL, __LINE__); \ - } else Y_CAT(YQL_LOG_CTX_LABEL, __LINE__): + goto Y_CAT(YQL_LOG_CTX_LABEL, __LINE__); \ + } else \ + Y_CAT(YQL_LOG_CTX_LABEL, __LINE__) \ + : #define YQL_PROFILE_FUNC(level) YQL_PROFILE_SCOPE(level, __FUNCTION__) #define YQL_PROFILE_FUNCSIG(level) YQL_PROFILE_SCOPE(level, Y_FUNC_SIGNATURE) @@ -35,7 +36,6 @@ #define YQL_PROFILE_FUNC_VAL(level) YQL_PROFILE_SCOPE_VAL(level, __FUNCTION__) #define YQL_PROFILE_FUNCSIG_VAL(level) YQL_PROFILE_SCOPE_VAL(level, Y_FUNC_SIGNATURE) - namespace NYql { namespace NLog { @@ -70,5 +70,5 @@ private: std::pair<TString, TString> LogCtxPath_; }; -} // namspace NLog -} // namspace NYql +} // namespace NLog +} // namespace NYql diff --git a/yql/essentials/utils/log/tls_backend.cpp b/yql/essentials/utils/log/tls_backend.cpp index a92f123c9bf..ec677fe8e8a 100644 --- a/yql/essentials/utils/log/tls_backend.cpp +++ b/yql/essentials/utils/log/tls_backend.cpp @@ -2,19 +2,18 @@ #include <util/system/tls.h> - namespace NYql { namespace NLog { namespace { Y_POD_STATIC_THREAD(TLogBackend*) CurrentBackend; -} // namspace +} // namespace TLogBackend* SetLogBackendForCurrentThread(TLogBackend* backend) { - TLogBackend* prev = *(&CurrentBackend); - *(&CurrentBackend) = backend; - return prev; + TLogBackend* prev = *(&CurrentBackend); + *(&CurrentBackend) = backend; + return prev; } void TTlsLogBackend::WriteData(const TLogRecord& rec) { @@ -45,5 +44,5 @@ ELogPriority TTlsLogBackend::FiltrationLevel() const { return LOG_MAX_PRIORITY; } -} // namspace NLog -} // namspace NYql +} // namespace NLog +} // namespace NYql diff --git a/yql/essentials/utils/log/tls_backend.h b/yql/essentials/utils/log/tls_backend.h index 802a73aae90..f8bded8bae7 100644 --- a/yql/essentials/utils/log/tls_backend.h +++ b/yql/essentials/utils/log/tls_backend.h @@ -6,7 +6,6 @@ #include <utility> - namespace NYql { namespace NLog { @@ -63,5 +62,5 @@ private: TLogBackend* PrevBacked_; }; -} // namspace NLog -} // namspace NYql +} // namespace NLog +} // namespace NYql diff --git a/yql/essentials/utils/log/tls_backend_ut.cpp b/yql/essentials/utils/log/tls_backend_ut.cpp index 96d77751316..e5496c746a3 100644 --- a/yql/essentials/utils/log/tls_backend_ut.cpp +++ b/yql/essentials/utils/log/tls_backend_ut.cpp @@ -15,7 +15,6 @@ #include <thread> #include <chrono> - using namespace NYql; using namespace NLog; @@ -53,72 +52,72 @@ private: Y_UNIT_TEST_SUITE(TTlsLogBackendTest) { - Y_UNIT_TEST_ON_EACH_LOG_FORMAT(CaptureOutputs) { - YqlLoggerScope logger(new TTlsLogBackend(new TNullLogBackend), Format); +Y_UNIT_TEST_ON_EACH_LOG_FORMAT(CaptureOutputs) { + YqlLoggerScope logger(new TTlsLogBackend(new TNullLogBackend), Format); - YQL_LOG(INFO) << "this message will be missed"; + YQL_LOG(INFO) << "this message will be missed"; - TRunnable r1("t1", 3); - std::thread t1(std::ref(r1)); + TRunnable r1("t1", 3); + std::thread t1(std::ref(r1)); - TRunnable r2("t2", 2); - std::thread t2(std::ref(r2)); + TRunnable r2("t2", 2); + std::thread t2(std::ref(r2)); - t1.join(); - t2.join(); + t1.join(); + t2.join(); -// Cout << "--[t1 logs]-----------------\n" << r1.GetLogs() << Endl; -// Cout << "--[t2 logs]-----------------\n" << r2.GetLogs() << Endl; + // Cout << "--[t1 logs]-----------------\n" << r1.GetLogs() << Endl; + // Cout << "--[t2 logs]-----------------\n" << r2.GetLogs() << Endl; - { // t1 - TString row1Str, row2Str, row3Str, _; - Split(r1.GetLogs(), '\n', row1Str, row2Str, row3Str, _); + { // t1 + TString row1Str, row2Str, row3Str, _; + Split(r1.GetLogs(), '\n', row1Str, row2Str, row3Str, _); - ui64 threadId = 0; - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT(logRow.ThreadId > 0); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t1"); - threadId = logRow.ThreadId; - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_EQUAL(logRow.ThreadId, threadId); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t1"); - } - { - TLogRow logRow = ParseLogRow(row3Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_EQUAL(logRow.ThreadId, threadId); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t1"); - } + ui64 threadId = 0; + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT(logRow.ThreadId > 0); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t1"); + threadId = logRow.ThreadId; + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_EQUAL(logRow.ThreadId, threadId); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t1"); } + { + TLogRow logRow = ParseLogRow(row3Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_EQUAL(logRow.ThreadId, threadId); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t1"); + } + } - { // t2 - TString row1Str, row2Str, _; - Split(r2.GetLogs(), '\n', row1Str, row2Str, _); - - ui64 threadId = 0; - { - TLogRow logRow = ParseLogRow(row1Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT(logRow.ThreadId > 0); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t2"); - threadId = logRow.ThreadId; - } - { - TLogRow logRow = ParseLogRow(row2Str); - UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); - UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); - UNIT_ASSERT_EQUAL(logRow.ThreadId, threadId); - UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t2"); - } + { // t2 + TString row1Str, row2Str, _; + Split(r2.GetLogs(), '\n', row1Str, row2Str, _); + + ui64 threadId = 0; + { + TLogRow logRow = ParseLogRow(row1Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT(logRow.ThreadId > 0); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t2"); + threadId = logRow.ThreadId; + } + { + TLogRow logRow = ParseLogRow(row2Str); + UNIT_ASSERT_EQUAL(logRow.Level, ELevel::INFO); + UNIT_ASSERT_EQUAL(logRow.Component, EComponent::Default); + UNIT_ASSERT_EQUAL(logRow.ThreadId, threadId); + UNIT_ASSERT_STRINGS_EQUAL(logRow.Message, "t2"); } } } +} // Y_UNIT_TEST_SUITE(TTlsLogBackendTest) diff --git a/yql/essentials/utils/log/ut/log_parser.cpp b/yql/essentials/utils/log/ut/log_parser.cpp index 461fd67cdbd..55f23ba0f57 100644 --- a/yql/essentials/utils/log/ut/log_parser.cpp +++ b/yql/essentials/utils/log/ut/log_parser.cpp @@ -4,67 +4,67 @@ namespace NYql::NLog { - TLogRow ParseJsonLogRow(TStringBuf str) { - NJson::TJsonMap json; - UNIT_ASSERT_C(NJson::ReadJsonTree(str, &json), "invalid json '" << str << "'"); +TLogRow ParseJsonLogRow(TStringBuf str) { + NJson::TJsonMap json; + UNIT_ASSERT_C(NJson::ReadJsonTree(str, &json), "invalid json '" << str << "'"); - return { - .Time = TInstant::ParseIso8601(json["@fields"]["datetime"].GetStringSafe()) - TDuration::Hours(4), - .Level = ELevelHelpers::FromString(json["@fields"]["level"].GetStringSafe()), - .ProcName = json["@fields"]["procname"].GetStringSafe(), - .ProcId = FromString<pid_t>(json["@fields"]["pid"].GetStringSafe()), - .ThreadId = [&] { - TString string = json["@fields"]["tid"].GetStringSafe(); - if (string.substr(0, 2) == "0x") { - return IntFromString<ui64, 16, TStringBuf>(string.substr(2)); - } else { - return IntFromString<ui64, 10, TStringBuf>(string); - } - }(), - .Component = EComponentHelpers::FromString(json["@fields"]["component"].GetStringSafe()), - .FileName = json["@fields"]["filename"].GetStringSafe(), - .LineNumber = FromString<ui32>(json["@fields"]["line"].GetStringSafe()), - .Path = json["@fields"]["path"].GetStringRobust(), - .Message = json["message"].GetStringSafe(), - }; - } + return { + .Time = TInstant::ParseIso8601(json["@fields"]["datetime"].GetStringSafe()) - TDuration::Hours(4), + .Level = ELevelHelpers::FromString(json["@fields"]["level"].GetStringSafe()), + .ProcName = json["@fields"]["procname"].GetStringSafe(), + .ProcId = FromString<pid_t>(json["@fields"]["pid"].GetStringSafe()), + .ThreadId = [&] { + TString string = json["@fields"]["tid"].GetStringSafe(); + if (string.substr(0, 2) == "0x") { + return IntFromString<ui64, 16, TStringBuf>(string.substr(2)); + } else { + return IntFromString<ui64, 10, TStringBuf>(string); + } + }(), + .Component = EComponentHelpers::FromString(json["@fields"]["component"].GetStringSafe()), + .FileName = json["@fields"]["filename"].GetStringSafe(), + .LineNumber = FromString<ui32>(json["@fields"]["line"].GetStringSafe()), + .Path = json["@fields"]["path"].GetStringRobust(), + .Message = json["message"].GetStringSafe(), + }; +} - TLogRow ParseLegacyLogRow(TStringBuf str) { - static std::regex rowRe( - "^([0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}\\.[0-9]{3}) " // (1) time - "([A-Z ]{5}) " // (2) level - "([a-zA-Z0-9_\\.-]+)" // (3) process name - ".pid=([0-9]+)," // (4) process id - " tid=(0?x?[0-9a-fA-F]+). " // (5) thread id - ".([a-zA-Z0-9_\\. ]+). " // (6) component name - "([^:]+):" // (7) file name - "([0-9]+): " // (8) line number - "(\\{[^\n]*\\} )?" // (9) path - "([^\n]*)\n?$" // (10) message - , std::regex_constants::extended); +TLogRow ParseLegacyLogRow(TStringBuf str) { + static std::regex rowRe( + "^([0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}\\.[0-9]{3}) " // (1) time + "([A-Z ]{5}) " // (2) level + "([a-zA-Z0-9_\\.-]+)" // (3) process name + ".pid=([0-9]+)," // (4) process id + " tid=(0?x?[0-9a-fA-F]+). " // (5) thread id + ".([a-zA-Z0-9_\\. ]+). " // (6) component name + "([^:]+):" // (7) file name + "([0-9]+): " // (8) line number + "(\\{[^\n]*\\} )?" // (9) path + "([^\n]*)\n?$" // (10) message + , std::regex_constants::extended); - std::cmatch match; - bool isMatch = std::regex_match(str.data(), match, rowRe); + std::cmatch match; + bool isMatch = std::regex_match(str.data(), match, rowRe); - UNIT_ASSERT_C(isMatch, "log row does not match format: '" << str << '\''); - UNIT_ASSERT_EQUAL_C(match.size(), 11, "expected 11 groups in log row: '" << str << '\''); + UNIT_ASSERT_C(isMatch, "log row does not match format: '" << str << '\''); + UNIT_ASSERT_EQUAL_C(match.size(), 11, "expected 11 groups in log row: '" << str << '\''); - return { - .Time = TInstant::ParseIso8601(match[1].str()) - TDuration::Hours(4), - .Level = ELevelHelpers::FromString(match[2].str()), - .ProcName = match[3].str(), - .ProcId = FromString<pid_t>(match[4].str()), - .ThreadId = match[5].str().substr(0, 2) == "0x" - ? IntFromString<ui64, 16, TStringBuf>(match[5].str().substr(2)) - : IntFromString<ui64, 10, TStringBuf>(match[5].str()), - .Component = EComponentHelpers::FromString(match[6].str()), - .FileName = match[7].str(), - .LineNumber = FromString<ui32>(match[8].str()), - .Path = match[9].str() != "" - ? match[9].str().substr(1, match[9].str().size() - 3) - : "", - .Message = match[10].str(), - }; - } + return { + .Time = TInstant::ParseIso8601(match[1].str()) - TDuration::Hours(4), + .Level = ELevelHelpers::FromString(match[2].str()), + .ProcName = match[3].str(), + .ProcId = FromString<pid_t>(match[4].str()), + .ThreadId = match[5].str().substr(0, 2) == "0x" + ? IntFromString<ui64, 16, TStringBuf>(match[5].str().substr(2)) + : IntFromString<ui64, 10, TStringBuf>(match[5].str()), + .Component = EComponentHelpers::FromString(match[6].str()), + .FileName = match[7].str(), + .LineNumber = FromString<ui32>(match[8].str()), + .Path = match[9].str() != "" + ? match[9].str().substr(1, match[9].str().size() - 3) + : "", + .Message = match[10].str(), + }; +} } // namespace NYql::NLog diff --git a/yql/essentials/utils/log/ut/log_parser.h b/yql/essentials/utils/log/ut/log_parser.h index a1bea046821..922000924b9 100644 --- a/yql/essentials/utils/log/ut/log_parser.h +++ b/yql/essentials/utils/log/ut/log_parser.h @@ -27,5 +27,5 @@ struct TLogRow { TLogRow ParseLegacyLogRow(TStringBuf str); TLogRow ParseJsonLogRow(TStringBuf str); -} // namspace NLog -} // namspace NYql +} // namespace NLog +} // namespace NYql diff --git a/yql/essentials/utils/log/ut/ya.make b/yql/essentials/utils/log/ut/ya.make index a78d4e0601b..3732c3f1ebc 100644 --- a/yql/essentials/utils/log/ut/ya.make +++ b/yql/essentials/utils/log/ut/ya.make @@ -1,5 +1,7 @@ UNITTEST_FOR(yql/essentials/utils/log) +ENABLE(YQL_STYLE_CPP) + SRCS( log_parser.cpp log_ut.cpp diff --git a/yql/essentials/utils/log/ya.make b/yql/essentials/utils/log/ya.make index 540b524c5eb..2a0d3dc3a4a 100644 --- a/yql/essentials/utils/log/ya.make +++ b/yql/essentials/utils/log/ya.make @@ -1,5 +1,7 @@ LIBRARY() +ENABLE(YQL_STYLE_CPP) + SRCS( context.cpp format.cpp |
