span with profile

6 files changed, 253 insertions, 0 deletions

diff --git a/library/cpp/actors/core/log.h b/library/cpp/actors/core/log.h
index 60469f5193a..e7cb9392a3d 100644
--- a/library/cpp/actors/core/log.h
+++ b/library/cpp/actors/core/log.h
@@ -32,6 +32,16 @@
              0ull)                                                                               \
     )
 
+#define IS_EMERG_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_EMERG, component)
+#define IS_ALERT_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_ALERT, component)
+#define IS_CRIT_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_CRIT, component)
+#define IS_ERROR_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_ERROR, component)
+#define IS_WARN_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_WARN, component)
+#define IS_NOTICE_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_NOTICE, component)
+#define IS_INFO_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_INFO, component)
+#define IS_DEBUG_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_DEBUG, component)
+#define IS_TRACE_LOG_ENABLED(component) IS_LOG_PRIORITY_ENABLED(*TlsActivationContext, NActors::NLog::PRI_TRACE, component)
+
 #define LOG_LOG_SAMPLED_BY(actorCtxOrSystem, priority, component, sampleBy, ...)                                               \
     do {                                                                                                                       \
         ::NActors::NLog::TSettings* mSettings = static_cast<::NActors::NLog::TSettings*>((actorCtxOrSystem).LoggerSettings()); \
diff --git a/library/cpp/actors/wilson/CMakeLists.txt b/library/cpp/actors/wilson/CMakeLists.txt
index 74661ec192b..91f380ee058 100644
--- a/library/cpp/actors/wilson/CMakeLists.txt
+++ b/library/cpp/actors/wilson/CMakeLists.txt
@@ -17,6 +17,9 @@ target_link_libraries(cpp-actors-wilson PUBLIC
   actors-wilson-protos
 )
 target_sources(cpp-actors-wilson PRIVATE
+  ${CMAKE_SOURCE_DIR}/library/cpp/actors/wilson/wilson_event.cpp
   ${CMAKE_SOURCE_DIR}/library/cpp/actors/wilson/wilson_span.cpp
+  ${CMAKE_SOURCE_DIR}/library/cpp/actors/wilson/wilson_profile_span.cpp
+  ${CMAKE_SOURCE_DIR}/library/cpp/actors/wilson/wilson_trace.cpp
   ${CMAKE_SOURCE_DIR}/library/cpp/actors/wilson/wilson_uploader.cpp
 )
diff --git a/library/cpp/actors/wilson/wilson_event.cpp b/library/cpp/actors/wilson/wilson_event.cpp
new file mode 100644
index 00000000000..ad51550d917
--- /dev/null
+++ b/library/cpp/actors/wilson/wilson_event.cpp
@@ -0,0 +1,4 @@
+#include "wilson_event.h"
+
+namespace NWilson {
+}
diff --git a/library/cpp/actors/wilson/wilson_profile_span.cpp b/library/cpp/actors/wilson/wilson_profile_span.cpp
new file mode 100644
index 00000000000..1748b280687
--- /dev/null
+++ b/library/cpp/actors/wilson/wilson_profile_span.cpp
@@ -0,0 +1,162 @@
+#include "wilson_profile_span.h"
+#include <library/cpp/json/writer/json.h>
+
+namespace NWilson {
+
+void TProfileSpan::AddMax(const TString& eventId, const TString& /*info*/) {
+    if (!Enabled) {
+        return;
+    }
+    auto it = PairInstances.find(eventId);
+    if (it == PairInstances.end()) {
+        PairInstances.emplace(eventId, TMinMaxPair::BuildMax(Now()));
+    } else {
+        it->second.AddMax(Now());
+    }
+}
+
+void TProfileSpan::AddMin(const TString& eventId, const TString& /*info*/) {
+    if (!Enabled) {
+        return;
+    }
+    auto it = PairInstances.find(eventId);
+    if (it == PairInstances.end()) {
+        PairInstances.emplace(eventId, TMinMaxPair::BuildMin(Now()));
+    } else {
+        it->second.AddMin(Now());
+    }
+}
+
+TString TProfileSpan::ProfileToString() const {
+    if (!Enabled) {
+        return "DISABLED";
+    }
+    TStringBuilder sb;
+    sb << "----FullDuration = " << Now() - StartTime << ";";
+    sb << "----Durations:";
+    FlushNoGuards();
+    {
+        NJsonWriter::TBuf sout;
+        ResultTimes.InsertValue("--current_guards_count", CurrentJsonPath.size());
+        ResultTimes.InsertValue("--duration", (Now() - StartTime).MicroSeconds() * 0.000001);
+        sout.WriteJsonValue(&ResultTimes, true, EFloatToStringMode::PREC_POINT_DIGITS, 6);
+        sb << sout.Str();
+    }
+    sb << ";";
+    sb << "----Pairs:{";
+    for (auto&& i : PairInstances) {
+        sb << i.first << ":" << i.second.ToString() << ";";
+    }
+    sb << "}";
+    return sb;
+}
+
+void TProfileSpan::FlushNoGuards() const {
+    if (!Enabled) {
+        return;
+    }
+    if (CurrentJsonPath.empty()) {
+        NJson::TJsonValue* currentNodeOutside;
+        if (!ResultTimes.GetValuePointer("--outside_duration", &currentNodeOutside)) {
+            currentNodeOutside = &ResultTimes.InsertValue("--outside_duration", 0);
+            currentNodeOutside->SetType(NJson::JSON_DOUBLE);
+        }
+        currentNodeOutside->SetValue(currentNodeOutside->GetDoubleRobust() + (Now() - LastNoGuards).MicroSeconds() * 0.000001);
+        LastNoGuards = Now();
+    }
+}
+
+NWilson::TProfileSpan::TMinMaxPair TProfileSpan::TMinMaxPair::BuildMin(const TInstant value) {
+    TMinMaxPair result;
+    result.MinMinInstance = value;
+    result.MaxMinInstance = value;
+    return result;
+}
+
+NWilson::TProfileSpan::TMinMaxPair TProfileSpan::TMinMaxPair::BuildMax(const TInstant value) {
+    TMinMaxPair result;
+    result.MaxInstance = value;
+    return result;
+}
+
+void TProfileSpan::TMinMaxPair::AddMax(const TInstant instance) {
+    if (!MaxInstance) {
+        MaxInstance = instance;
+    } else {
+        MaxInstance = Max(*MaxInstance, instance);
+    }
+}
+
+void TProfileSpan::TMinMaxPair::AddMin(const TInstant instance) {
+    if (!MinMinInstance) {
+        MinMinInstance = instance;
+    } else {
+        MinMinInstance = Min(*MinMinInstance, instance);
+    }
+    if (!MaxMinInstance) {
+        MaxMinInstance = instance;
+    } else {
+        MaxMinInstance = Max(*MaxMinInstance, instance);
+    }
+}
+
+TString TProfileSpan::TMinMaxPair::ToString() const {
+    TStringBuilder sb;
+    sb << "[";
+    if (MinMinInstance) {
+        sb << MinMinInstance->MicroSeconds();
+    } else {
+        sb << "UNDEFINED";
+    }
+    sb << "-";
+    if (MaxMinInstance) {
+        sb << MaxMinInstance->MicroSeconds();
+    } else {
+        sb << "UNDEFINED";
+    }
+    sb << ",";
+    if (MaxInstance) {
+        sb << MaxInstance->MicroSeconds();
+    } else {
+        sb << "UNDEFINED";
+    }
+    if (MaxInstance && MinMinInstance) {
+        sb << ",";
+        sb << *MaxInstance - *MaxMinInstance << "-" << *MaxInstance - *MinMinInstance;
+    }
+    sb << "]";
+    return sb;
+}
+
+TProfileSpan::TGuard::~TGuard() {
+    if (!Owner.Enabled) {
+        return;
+    }
+    Y_VERIFY(CurrentNodeDuration->IsDouble());
+    CurrentNodeDuration->SetValue((Now() - Start).MicroSeconds() * 0.000001 + CurrentNodeDuration->GetDoubleRobust());
+    Y_VERIFY(Owner.CurrentJsonPath.size());
+    Owner.CurrentJsonPath.pop_back();
+    if (Owner.CurrentJsonPath.empty()) {
+        Owner.LastNoGuards = Now();
+    }
+}
+
+TProfileSpan::TGuard::TGuard(const TString& event, TProfileSpan& owner, const TString& /*info*/)
+    : Owner(owner) {
+    if (!Owner.Enabled) {
+        return;
+    }
+    Owner.FlushNoGuards();
+    NJson::TJsonValue* currentNode = Owner.CurrentJsonPath.empty() ? &Owner.ResultTimes : Owner.CurrentJsonPath.back();
+    NJson::TJsonValue* currentNodeParent;
+    if (!currentNode->GetValuePointer(event, &currentNodeParent)) {
+        currentNodeParent = &currentNode->InsertValue(event, NJson::JSON_MAP);
+    }
+    Owner.CurrentJsonPath.emplace_back(currentNodeParent);
+    if (!currentNodeParent->GetValuePointer("--duration", &CurrentNodeDuration)) {
+        CurrentNodeDuration = &currentNodeParent->InsertValue("--duration", 0);
+        CurrentNodeDuration->SetType(NJson::JSON_DOUBLE);
+    }
+}
+
+} // NWilson
diff --git a/library/cpp/actors/wilson/wilson_profile_span.h b/library/cpp/actors/wilson/wilson_profile_span.h
new file mode 100644
index 00000000000..20bde7857c4
--- /dev/null
+++ b/library/cpp/actors/wilson/wilson_profile_span.h
@@ -0,0 +1,70 @@
+#pragma once
+#include "wilson_span.h"
+#include <library/cpp/json/writer/json_value.h>
+
+namespace NWilson {
+
+class TProfileSpan: public TSpan {
+private:
+    using TBase = TSpan;
+    class TMinMaxPair {
+    private:
+        std::optional<TInstant> MinMinInstance;
+        std::optional<TInstant> MaxMinInstance;
+        std::optional<TInstant> MaxInstance;
+    public:
+        static TMinMaxPair BuildMin(const TInstant value);
+        static TMinMaxPair BuildMax(const TInstant value);
+        void AddMax(const TInstant instance);
+        void AddMin(const TInstant instance);
+        TString ToString() const;
+    };
+    mutable NJson::TJsonValue ResultTimes;
+    std::map<TString, TMinMaxPair> PairInstances;
+    std::vector<NJson::TJsonValue*> CurrentJsonPath;
+    mutable TInstant LastNoGuards = Now();
+    const TInstant StartTime = Now();
+    bool Enabled = true;
+
+    void FlushNoGuards() const;
+    TProfileSpan() = default;
+public:
+    using TBase::TBase;
+    TString ProfileToString() const;
+
+    TProfileSpan& SetEnabled(const bool value) {
+        Enabled = value;
+        return *this;
+    }
+
+    class TGuard {
+    private:
+        TProfileSpan& Owner;
+        const TInstant Start = Now();
+        NJson::TJsonValue* CurrentNodeDuration;
+    public:
+        TGuard(const TString& event, TProfileSpan& owner, const TString& info);
+        ~TGuard();
+    };
+
+    template <class TEventId, class T = TString>
+    TGuard StartStackTimeGuard(const TEventId event, const T& info = Default<T>()) {
+        return TGuard(::ToString(event), *this, ::ToString(info));
+    }
+
+    template <class TEventId, class T = TString>
+    void AddMin(const TEventId event, const T& info = Default<T>()) {
+        AddMin(::ToString(event), ::ToString(info));
+    }
+
+    template <class TEventId, class T = TString>
+    void AddMax(const TEventId event, const T& info = Default<T>()) {
+        AddMax(::ToString(event), ::ToString(info));
+    }
+
+    void AddMin(const TString& eventId, const TString& info);
+    void AddMax(const TString& eventId, const TString& info);
+
+};
+
+} // NWilson
diff --git a/library/cpp/actors/wilson/wilson_trace.cpp b/library/cpp/actors/wilson/wilson_trace.cpp
new file mode 100644
index 00000000000..73bed31da3b
--- /dev/null
+++ b/library/cpp/actors/wilson/wilson_trace.cpp
@@ -0,0 +1,4 @@
+#include "wilson_trace.h"
+
+namespace NWilson {
+}