S3: have the first working version using MultiPart uploads (for the m…

…oment unoptimized enforced) S3: add logging for survival and some simple timing benchmark into the router function to display how long requests are running
cern-eos · Jun 19, 2024 · 3681a3f · 3681a3f
1 parent 8805939
commit 3681a3f
Show file tree

Hide file tree

Showing 11 changed files with 470 additions and 175 deletions.
diff --git a/src/XrdS3/XrdS3.cc b/src/XrdS3/XrdS3.cc
@@ -576,11 +576,11 @@ bool S3Handler::ParseConfig(const char *config, XrdOucEnv &env) {
       }
       mConfig.trace = val;
       mErr.setMsgMask(0);
-      if (!strcmp(val, "all"))          {mErr.setMsgMask(mErr.getMsgMask() | LogMask::ALL);}
-      else if (!strcmp(val, "error"))   {mErr.setMsgMask(mErr.getMsgMask() | LogMask::ERROR);}
-      else if (!strcmp(val, "warning")) {mErr.setMsgMask(mErr.getMsgMask() | LogMask::WARN);}
-      else if (!strcmp(val, "info"))    {mErr.setMsgMask(mErr.getMsgMask() | LogMask::INFO);}
-      else if (!strcmp(val, "debug"))   {mErr.setMsgMask(mErr.getMsgMask() | LogMask::DEBUG);}
+      if (!strcmp(val, "all"))          {mErr.setMsgMask(LogMask::ALL);}
+      else if (!strcmp(val, "error"))   {mErr.setMsgMask(LogMask::ERROR);}
+      else if (!strcmp(val, "warning")) {mErr.setMsgMask(LogMask::ERROR | LogMask::WARN);}
+      else if (!strcmp(val, "info"))    {mErr.setMsgMask(LogMask::ERROR | LogMask::WARN | LogMask::INFO);}
+      else if (!strcmp(val, "debug"))   {mErr.setMsgMask(LogMask::ERROR | LogMask::WARN | LogMask::INFO | LogMask::DEBUG);}
       else if (!strcmp(val, "none"))    {mErr.setMsgMask(0);}
       else {
         std::cerr << "error: s3.trace encountered an unknown directive: " << val << std::endl;

diff --git a/src/XrdS3/XrdS3Api.cc b/src/XrdS3/XrdS3Api.cc
@@ -696,6 +696,7 @@ int S3Api::ListObjectsV2Handler(S3::XrdS3Req& req) {
   bool encode_values;
   int max_keys;
 
+  std::cerr << "HANDLING LISTING" << std::endl;
   RET_ON_ERROR(ParseCommonQueryParams(req.query, delimiter, encode_values,
                                       max_keys, prefix))
 
@@ -720,6 +721,7 @@ int S3Api::ListObjectsV2Handler(S3::XrdS3Req& req) {
     }
   }
 
+  std::cerr << "calling object store list objects v2" << std::endl;
   auto objectinfo =
       objectStore.ListObjectsV2(bucket, prefix, continuation_token, delimiter,
                                 max_keys, fetch_owner, start_after);

diff --git a/src/XrdS3/XrdS3Auth.cc b/src/XrdS3/XrdS3Auth.cc
@@ -4,6 +4,7 @@
 
 //------------------------------------------------------------------------------
 #include "XrdS3Auth.hh"
+#include "XrdS3.hh"
 //------------------------------------------------------------------------------
 #include <fcntl.h>
 #include <sys/xattr.h>
@@ -236,9 +237,7 @@ S3Error S3Auth::VerifySigV4(XrdS3Req &req) {
       AWS4_ALGORITHM, req.date, canonical_request_hash, sig.credentials);
 
   const auto signature = GetSignature(key, sig.credentials, string_to_sign);
-  ctx->log->Emsg("VerifySignature", "calculated signature:", signature.c_str());
-  ctx->log->Emsg("VerifySignature",
-                 "  received signature:", sig.signature.c_str());
+  S3::S3Handler::Logger()->Log(S3::DEBUG, "VerifySignature", "sign=%s calc-sign=%s", sig.signature.c_str(), signature.c_str());
 
   if (signature == sig.signature) {
     return S3Error::None;

diff --git a/src/XrdS3/XrdS3Log.hh b/src/XrdS3/XrdS3Log.hh
@@ -37,20 +37,43 @@ namespace S3 {
   //------------------------------------------------------------------------------
   enum LogMask {
                 DEBUG = 0x01,
-                INFO = 0x02,
+		INFO = 0x02,
                 WARN = 0x04,
                 ERROR = 0x08,
                 ALL = 0xff
   };
-  
+
   //------------------------------------------------------------------------------
   //! \brief class to log from S3 plug-in
   //------------------------------------------------------------------------------
   class S3Log {
   public:
-    S3Log(XrdSysError& mErr) : mLog(&mErr) {}
+    S3Log(XrdSysError& mErr) : mLog(&mErr), traceId(0) {}
     S3Log() {}
     virtual ~S3Log() {}
+
+    std::string LogString(int c)  {
+      switch (c) {
+      case DEBUG:
+	return "| DEBUG |";
+      case INFO:
+	return "| INFO  |";
+      case WARN:
+	return "| REQU  |";
+      case ERROR:
+	return "| ERROR |";
+      default:
+      return "| INIT  |";
+      }
+    };
+
+    std::string newTrace() {
+      std::lock_guard<std::mutex> guard(logMutex); 
+      traceId++;
+      std::stringstream ss;
+      ss << "[req:" << std::setw(8) << std::setfill('0') << std::hex << traceId << "]";
+      return ss.str();
+    }
 
     //! \brief initialize logging
     void Init(XrdSysError* log) { mLog = log; }
@@ -59,19 +82,25 @@ namespace S3 {
     std::string
     Log(S3::LogMask mask, const char* unit, const char* msg, ...)
     {
-      std::lock_guard<std::mutex> guard(logMutex); 
-
+      std::lock_guard<std::mutex> guard(logMutex);
       va_list args;
       va_start(args, msg);
       vsnprintf(logBuffer, sizeof(logBuffer), msg, args);
       va_end(args);
-      mLog->Log( (int) mask, unit, logBuffer );
+      std::string tag = std::string("X") + LogString(mask) + std::string(" ") + unit;
+      int l = 48-tag.size();
+      for ( auto i=0 ; i<l; ++i) {
+	tag += " ";
+      }
+
+      mLog->Log( (int) mask, tag.c_str() , logBuffer );
       return std::string(logBuffer);
     }
 
   private:
     XrdSysError* mLog;
     char logBuffer[65535]; 
-    std::mutex logMutex; 
+    std::mutex logMutex;
+    uint64_t traceId;
   };
 }