UdfResolver analytics

commit_hash:393ec43ede4bf529dd68413165afce4bb49a43db

6 files changed, 105 insertions, 15 deletions

diff --git a/yql/essentials/providers/common/udf_resolve/ya.make b/yql/essentials/providers/common/udf_resolve/ya.make
index 65fa463b8c4..fec4639561f 100644
--- a/yql/essentials/providers/common/udf_resolve/ya.make
+++ b/yql/essentials/providers/common/udf_resolve/ya.make
@@ -9,6 +9,7 @@ SRCS(
     yql_simple_udf_resolver.h
     yql_udf_resolver_with_index.cpp
     yql_udf_resolver_with_index.h
+    yql_udf_resolver_logger.cpp
 )
 
 PEERDIR(
diff --git a/yql/essentials/providers/common/udf_resolve/yql_outproc_udf_resolver.cpp b/yql/essentials/providers/common/udf_resolve/yql_outproc_udf_resolver.cpp
index 778dfc16388..9858c6ee256 100644
--- a/yql/essentials/providers/common/udf_resolve/yql_outproc_udf_resolver.cpp
+++ b/yql/essentials/providers/common/udf_resolve/yql_outproc_udf_resolver.cpp
@@ -4,7 +4,6 @@
 
 #include <yql/essentials/providers/common/proto/udf_resolver.pb.h>
 #include <yql/essentials/providers/common/schema/expr/yql_expr_schema.h>
-#include <yql/essentials/core/yql_holding_file_storage.h>
 #include <yql/essentials/core/yql_type_annotation.h>
 #include <yql/essentials/utils/log/log.h>
 #include <yql/essentials/utils/retry.h>
@@ -139,7 +138,7 @@ public:
         return FunctionRegistry_->IsLoadedUdfModule(moduleName);
     }
 
-    bool LoadMetadata(const TVector<TImport*>& imports, const TVector<TFunction*>& functions, TExprContext& ctx, NUdf::ELogLevel logLevel) const override {
+    bool LoadMetadata(const TVector<TImport*>& imports, const TVector<TFunction*>& functions, TExprContext& ctx, NUdf::ELogLevel logLevel, THoldingFileStorage& storage) const override {
         THashSet<TString> requiredLoadedModules;
         THashSet<TString> requiredExternalModules;
         TVector<TFunction*> loadedFunctions;
@@ -166,7 +165,6 @@ public:
         TResolve request;
         request.SetRuntimeLogLevel(static_cast<ui32>(logLevel));
         TVector<TImport*> usedImports;
-        THoldingFileStorage holdingFileStorage(FileStorage_);
         THolder<TFilesBox> filesBox = CreateFilesBoxOverFileStorageTemp();
 
         THashMap<TString, TImport*> path2LoadedImport;
@@ -194,7 +192,7 @@ public:
             }
 
             try {
-                LoadImport(holdingFileStorage, *filesBox, *import, request);
+                LoadImport(storage, *filesBox, *import, request);
                 usedImports.push_back(import);
             } catch (const std::exception& e) {
                 ctx.AddError(ExceptionToIssue(e));
@@ -247,17 +245,16 @@ public:
         return !hasErrors;
     }
 
-    TResolveResult LoadRichMetadata(const TVector<TImport>& imports, NUdf::ELogLevel logLevel) const override {
+    TResolveResult LoadRichMetadata(const TVector<TImport>& imports, NUdf::ELogLevel logLevel, THoldingFileStorage& storage) const override {
         TResolve request;
         request.SetRuntimeLogLevel(static_cast<ui32>(logLevel));
-        THoldingFileStorage holdingFileStorage(FileStorage_);
         THolder<TFilesBox> filesBox = CreateFilesBoxOverFileStorageTemp();
         Y_DEFER {
             filesBox->Destroy();
         };
 
         for (auto import : imports) {
-            LoadImport(holdingFileStorage, *filesBox, import, request);
+            LoadImport(storage, *filesBox, import, request);
         }
 
         return RunResolverAndParseResult(request, { "--discover-proto" }, *filesBox);
diff --git a/yql/essentials/providers/common/udf_resolve/yql_simple_udf_resolver.cpp b/yql/essentials/providers/common/udf_resolve/yql_simple_udf_resolver.cpp
index 9ec1aa2b52c..8b19fdc1d85 100644
--- a/yql/essentials/providers/common/udf_resolve/yql_simple_udf_resolver.cpp
+++ b/yql/essentials/providers/common/udf_resolve/yql_simple_udf_resolver.cpp
@@ -51,7 +51,7 @@ public:
     }
 
     bool LoadMetadata(const TVector<TImport*>& imports,
-        const TVector<TFunction*>& functions, TExprContext& ctx, NUdf::ELogLevel logLevel) const override {
+        const TVector<TFunction*>& functions, TExprContext& ctx, NUdf::ELogLevel logLevel, THoldingFileStorage& storage) const override {
 
         with_lock(Lock_) {
             bool hasErrors = false;
@@ -68,7 +68,6 @@ public:
                 }
             }
 
-            THoldingFileStorage holdingFileStorage(FileStorage_);
             auto newRegistry = FunctionRegistry_->Clone();
             THashMap<std::pair<TString, TString>, THashSet<TString>> cachedModules;
             for (auto import: imports) {
@@ -91,7 +90,7 @@ public:
                 try {
                     THashSet<TString> modules;
                     if (FileStorage_) {
-                        auto link = holdingFileStorage.FreezeFile(*import->Block);
+                        auto link = storage.FreezeFile(*import->Block);
                         auto path = link->GetPath().GetPath();
                         auto [it, inserted] = cachedModules.emplace(std::make_pair(path, customUdfPrefix), THashSet<TString>());
                         if (inserted) {
@@ -141,7 +140,7 @@ public:
         }
     }
 
-    TResolveResult LoadRichMetadata(const TVector<TImport>& imports, NUdf::ELogLevel logLevel) const override {
+    TResolveResult LoadRichMetadata(const TVector<TImport>& imports, NUdf::ELogLevel logLevel, THoldingFileStorage&) const override {
         Y_UNUSED(imports);
         Y_UNUSED(logLevel);
         ythrow yexception() << "LoadRichMetadata is not supported in SimpleUdfResolver";
diff --git a/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_logger.cpp b/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_logger.cpp
new file mode 100644
index 00000000000..5cb14c7619c
--- /dev/null
+++ b/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_logger.cpp
@@ -0,0 +1,83 @@
+#include "yql_udf_resolver_logger.h"
+
+#include <yql/essentials/core/yql_user_data_storage.h>
+
+#include <util/stream/file.h>
+#include <util/string/builder.h>
+#include <util/datetime/cputimer.h>
+
+namespace {
+using namespace NYql;
+
+class TUdfResolverWithLoggerDecorator : public IUdfResolver {
+public:
+    TUdfResolverWithLoggerDecorator(IUdfResolver::TPtr underlying, const TString& path, const TString& sessionId)
+        : Underlying_(underlying), Out_(TFile(path, WrOnly | ForAppend)), SessionId_(sessionId) {}
+
+    TMaybe<TFilePathWithMd5> GetSystemModulePath(const TStringBuf& moduleName) const override {
+        return Underlying_->GetSystemModulePath(moduleName);
+    }
+
+    bool LoadMetadata(
+        const TVector<TImport*>& imports, const TVector<TFunction*>& functions,
+        TExprContext& ctx, NUdf::ELogLevel logLevel, THoldingFileStorage& storage) const override
+    {
+        TSimpleTimer t;
+        auto result = Underlying_->LoadMetadata(imports, functions, ctx, logLevel, storage);
+        auto runningTime = t.Get().MilliSeconds();
+
+        TStringBuilder sb;
+        sb << SessionId_ << " LoadMetadata with imports (";
+        for (auto& e: imports) {
+            if (!e || !e->Block) {
+                continue;
+            }
+            auto frozen = e->Block->Type != EUserDataType::URL ? e->Block->FrozenFile : storage.GetFrozenBlock(*e->Block);
+            if (!frozen) {
+                continue;
+            }
+            sb << " " << frozen->GetMd5() << ":" << frozen->GetSize();
+        }
+        sb << ") took " << runningTime << " ms\n";
+        Out_ << TString(sb);
+        return result;
+    }
+
+    TResolveResult LoadRichMetadata(const TVector<TImport>& imports, NUdf::ELogLevel logLevel, THoldingFileStorage& storage) const override {
+        TSimpleTimer t;
+        auto result = Underlying_->LoadRichMetadata(imports, logLevel, storage);
+        auto runningTime = t.Get().MilliSeconds();
+
+        TStringBuilder sb;
+        sb << SessionId_ << " LoadRichMetadata with imports (";
+        for (auto& e: imports) {
+            if (!e.Block) {
+                continue;
+            }
+            auto frozen = e.Block->Type != EUserDataType::URL ? e.Block->FrozenFile : storage.GetFrozenBlock(*e.Block);
+            if (!frozen) {
+                continue;
+            }
+            sb << " " << frozen->GetMd5() << ":" << frozen->GetSize();
+        }
+        sb << ") took " << runningTime << " ms\n";
+        Out_ << TString(sb);
+        return result;
+    }
+
+    bool ContainsModule(const TStringBuf& moduleName) const override {
+        return Underlying_->ContainsModule(moduleName);
+    }
+private:
+    IUdfResolver::TPtr Underlying_;
+    mutable TUnbufferedFileOutput Out_;
+    TString SessionId_;
+};
+
+}
+
+namespace NYql::NCommon {
+IUdfResolver::TPtr CreateUdfResolverDecoratorWithLogger(IUdfResolver::TPtr underlying, const TString& path, const TString& sessionId) {
+    return new TUdfResolverWithLoggerDecorator(underlying, path, sessionId);
+}
+}
diff --git a/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_logger.h b/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_logger.h
new file mode 100644
index 00000000000..f899cc46e65
--- /dev/null
+++ b/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_logger.h
@@ -0,0 +1,10 @@
+#pragma once
+
+#include <yql/essentials/core/yql_udf_index.h>
+#include <yql/essentials/core/file_storage/file_storage.h>
+
+namespace NYql::NCommon {
+
+IUdfResolver::TPtr CreateUdfResolverDecoratorWithLogger(IUdfResolver::TPtr underlying, const TString& path, const TString& sessionId);
+
+} // namespace NYql::NCommon
diff --git a/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_with_index.cpp b/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_with_index.cpp
index 689962c4e2e..3892de463e7 100644
--- a/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_with_index.cpp
+++ b/yql/essentials/providers/common/udf_resolve/yql_udf_resolver_with_index.cpp
@@ -79,7 +79,7 @@ public:
     }
 
     bool LoadMetadata(const TVector<TImport*>& imports, const TVector<TFunction*>& functions,
-        TExprContext& ctx, NUdf::ELogLevel logLevel) const override {
+        TExprContext& ctx, NUdf::ELogLevel logLevel, THoldingFileStorage& storage) const override {
         with_lock(Lock_) {
             bool hasErrors = false;
             THashSet<TString> requiredModules;
@@ -106,12 +106,12 @@ public:
 
             fallbackImports.insert(fallbackImports.end(), additionalImports.begin(), additionalImports.end());
 
-            return Fallback_->LoadMetadata(fallbackImports, fallbackFunctions, ctx, logLevel) && !hasErrors;
+            return Fallback_->LoadMetadata(fallbackImports, fallbackFunctions, ctx, logLevel, storage) && !hasErrors;
         }
     }
 
-    TResolveResult LoadRichMetadata(const TVector<TImport>& imports, NUdf::ELogLevel logLevel) const override {
-        return Fallback_->LoadRichMetadata(imports, logLevel);
+    TResolveResult LoadRichMetadata(const TVector<TImport>& imports, NUdf::ELogLevel logLevel, THoldingFileStorage& storage) const override {
+        return Fallback_->LoadRichMetadata(imports, logLevel, storage);
     }
 
     bool ContainsModule(const TStringBuf& moduleName) const override {