Conditional logging of request body (#2520)

Author: nshestakov

ydb/core/client/server/grpc_server.cpp

@@ -11,8 +11,6 @@
 
 #include <util/string/join.h>
 
-#include <google/protobuf/text_format.h>
-
 #include <grpc++/resource_quota.h>
 #include <grpc++/security/server_credentials.h>
 #include <grpc++/server_builder.h>
@@ -266,15 +264,8 @@ class TSimpleRequest
     }
 
     void Finish(const TOut& resp, ui32 status) {
-        auto makeResponseString = [&] {
-            TString x;
-            google::protobuf::TextFormat::Printer printer;
-            printer.SetSingleLineMode(true);
-            printer.PrintToString(resp, &x);
-            return x;
-        };
         LOG_DEBUG(ActorSystem, NKikimrServices::GRPC_SERVER, "[%p] issuing response Name# %s data# %s peer# %s", this,
-            Name, makeResponseString().data(), GetPeerName().c_str());
+            Name, NYdbGrpc::FormatMessage(resp).data(), GetPeerName().c_str());
         ResponseSize = resp.ByteSize();
         ResponseStatus = status;
         StateFunc = &TSimpleRequest::FinishDone;
@@ -300,19 +291,8 @@ class TSimpleRequest
     bool RequestDone(bool ok) {
         OnAfterCall();
 
-        auto makeRequestString = [&] {
-            TString resp;
-            if (ok) {
-                google::protobuf::TextFormat::Printer printer;
-                printer.SetSingleLineMode(true);
-                printer.PrintToString(Request, &resp);
-            } else {
-                resp = "<not ok>";
-            }
-            return resp;
-        };
         LOG_DEBUG(ActorSystem, NKikimrServices::GRPC_SERVER, "[%p] received request Name# %s ok# %s data# %s peer# %s current inflight# %li", this,
-            Name, ok ? "true" : "false", makeRequestString().data(), GetPeerName().c_str(), Server->GetCurrentInFlight());
+            Name, ok ? "true" : "false", NYdbGrpc::FormatMessage(Request, ok).data(), GetPeerName().c_str(), Server->GetCurrentInFlight());
 
         if (Context.c_call() == nullptr) {
             Y_ABORT_UNLESS(!ok);

ydb/core/grpc_streaming/grpc_streaming.h

@@ -11,7 +11,6 @@
 
 #include <contrib/libs/grpc/include/grpcpp/support/async_stream.h>
 #include <contrib/libs/grpc/include/grpcpp/support/async_unary_call.h>
-#include <google/protobuf/text_format.h>
 
 #include <atomic>
 
@@ -347,22 +346,10 @@ class TGRpcStreamingRequest final
     }
 
     void OnReadDone(NYdbGrpc::EQueueEventStatus status) {
-        auto dumpResultText = [&] {
-            TString text;
-            if (status == NYdbGrpc::EQueueEventStatus::OK) {
-                google::protobuf::TextFormat::Printer printer;
-                printer.SetSingleLineMode(true);
-                printer.PrintToString(ReadInProgress->Record, &text);
-            } else {
-                text = "<not ok>";
-            }
-            return text;
-        };
-
         LOG_DEBUG(ActorSystem, LoggerServiceId, "[%p] read finished Name# %s ok# %s data# %s peer# %s",
             this, Name,
             status == NYdbGrpc::EQueueEventStatus::OK ? "true" : "false",
-            dumpResultText().c_str(),
+            NYdbGrpc::FormatMessage(ReadInProgress->Record, status == NYdbGrpc::EQueueEventStatus::OK).c_str(),
             this->GetPeerName().c_str());
 
         // Take current in-progress read first
@@ -400,25 +387,17 @@ class TGRpcStreamingRequest final
     }
 
     bool Write(TOut&& message, const grpc::WriteOptions& options = { }, const grpc::Status* status = nullptr) {
-        auto dumpMessageText = [&] {
-            TString text;
-            google::protobuf::TextFormat::Printer printer;
-            printer.SetSingleLineMode(true);
-            printer.PrintToString(message, &text);
-            return text;
-        };
-
         if (status) {
             LOG_DEBUG(ActorSystem, LoggerServiceId, "[%p] facade write Name# %s data# %s peer# %s grpc status# (%d) message# %s",
                 this, Name,
-                dumpMessageText().c_str(),
+                NYdbGrpc::FormatMessage(message).c_str(),
                 this->GetPeerName().c_str(),
                 static_cast<int>(status->error_code()),
                 status->error_message().c_str());
         } else {
             LOG_DEBUG(ActorSystem, LoggerServiceId, "[%p] facade write Name# %s data# %s peer# %s",
                 this, Name,
-                dumpMessageText().c_str(),
+                NYdbGrpc::FormatMessage(message).c_str(),
                 this->GetPeerName().c_str());
         }
 

ydb/library/grpc/server/logger.h

@@ -3,9 +3,15 @@
 #include <library/cpp/logger/priority.h>
 
 #include <util/generic/ptr.h>
+#include <util/system/env.h>
+
+#include <google/protobuf/text_format.h>
+
 
 namespace NYdbGrpc {
 
+static bool LogBodyEnabled = "BODY" == GetEnv("YDB_GRPC_SERVER_LOGGING");    
+
 class TLogger: public TThrRefBase {
 protected:
     TLogger() = default;
@@ -40,4 +46,21 @@ using TLoggerPtr = TIntrusivePtr<TLogger>;
         logger->Write(ELogPriority::TLOG_INFO, format, __VA_ARGS__); \
     } else { }
 
+
+inline TString FormatMessage(const NProtoBuf::Message& message, bool ok = true) {
+    if (ok) {
+        if (LogBodyEnabled) {
+            TString text;
+            google::protobuf::TextFormat::Printer printer;
+            printer.SetSingleLineMode(true);
+            printer.PrintToString(message, &text);
+            return text;
+        } else {
+            return "<hidden>";
+        }
+    } else {
+        return "<not ok>";
+    }
+}
+
 } // namespace NYdbGrpc