changeset 4270:251a8b07fa37

logging categories
author Sebastien Jodogne <s.jodogne@gmail.com>
date Mon, 02 Nov 2020 18:45:50 +0100
parents c7bd2f21ccc3
children 1bd14c900699
files NEWS OrthancFramework/Sources/Logging.cpp OrthancFramework/Sources/Logging.h OrthancFramework/UnitTestsSources/LoggingTests.cpp OrthancServer/Sources/main.cpp
diffstat 5 files changed, 303 insertions(+), 34 deletions(-) [+]
line wrap: on
line diff
--- a/NEWS	Mon Nov 02 17:15:57 2020 +0100
+++ b/NEWS	Mon Nov 02 18:45:50 2020 +0100
@@ -1,6 +1,7 @@
 Pending changes in the mainline
 ===============================
 
+* Logging categories (check out command-line options "--verbose=" and "--trace=")
 * C-GET SCP: Fix responses and handling of cancel
 * Fix decoding sequence if "BuiltinDecoderTranscoderOrder" is "Before"
 * REST API returns 404 error if deleting an inexistent peer or modality
--- a/OrthancFramework/Sources/Logging.cpp	Mon Nov 02 17:15:57 2020 +0100
+++ b/OrthancFramework/Sources/Logging.cpp	Mon Nov 02 18:45:50 2020 +0100
@@ -34,8 +34,10 @@
 {
   namespace Logging
   {
-    static bool infoEnabled_ = false;
-    static bool traceEnabled_ = false;
+    static const uint32_t ALL_CATEGORIES_MASK = 0xffffffff;
+    
+    static uint32_t infoCategoriesMask_ = 0;
+    static uint32_t traceCategoriesMask_ = 0;
     
     const char* EnumerationToString(LogLevel level)
     {
@@ -83,40 +85,87 @@
       }
     }
 
+    
     void EnableInfoLevel(bool enabled)
     {
-      infoEnabled_ = enabled;
-
-      if (!enabled)
+      if (enabled)
+      {
+        infoCategoriesMask_ = ALL_CATEGORIES_MASK;
+      }
+      else
       {
         // Also disable the "TRACE" level when info-level debugging is disabled
-        traceEnabled_ = false;
+        infoCategoriesMask_ = 0;
+        traceCategoriesMask_ = 0;
+      }
+    }
+
+    
+    bool IsInfoLevelEnabled()
+    {
+      return (infoCategoriesMask_ != 0);
+    }
+
+    
+    void EnableTraceLevel(bool enabled)
+    {
+      if (enabled)
+      {
+        // Also enable the "INFO" level when trace-level debugging is enabled
+        infoCategoriesMask_ = ALL_CATEGORIES_MASK;
+        traceCategoriesMask_ = ALL_CATEGORIES_MASK;
+      }
+      else
+      {
+        traceCategoriesMask_ = 0;
       }
     }
 
-    bool IsInfoLevelEnabled()
+
+    bool IsTraceLevelEnabled()
     {
-      return infoEnabled_;
+      return (traceCategoriesMask_ != 0);
     }
 
-    void EnableTraceLevel(bool enabled)
+    
+    void SetCategoryEnabled(LogLevel level,
+                            LogCategory category,
+                            bool enabled)
     {
-      traceEnabled_ = enabled;
-            
-      if (enabled)
+      if (level == LogLevel_INFO)
+      {
+        if (enabled)
+        {
+          infoCategoriesMask_ |= static_cast<uint32_t>(category);
+        }
+        else
+        {
+          infoCategoriesMask_ &= ~static_cast<uint32_t>(category);
+          traceCategoriesMask_ &= ~static_cast<uint32_t>(category);
+        }
+      }
+      else if (level == LogLevel_TRACE)
       {
-        // Also enable the "INFO" level when trace-level debugging is enabled
-        infoEnabled_ = true;
+        if (enabled)
+        {
+          traceCategoriesMask_ |= static_cast<uint32_t>(category);
+          infoCategoriesMask_ |= static_cast<uint32_t>(category);
+        }
+        else
+        {
+          traceCategoriesMask_ &= ~static_cast<uint32_t>(category);
+        }
+      }
+      else
+      {
+        throw OrthancException(ErrorCode_ParameterOutOfRange,
+                               "Can only modify the parameters of the INFO and TRACE levels");
       }
     }
 
-    bool IsTraceLevelEnabled()
-    {
-      return traceEnabled_;
-    }
-
-    static bool IsLoggingEnabled(LogLevel level,
-                                 LogCategory category)
+    
+    bool IsCategoryEnabled(LogLevel level,
+                           LogCategory category)
     {
       if (level == LogLevel_ERROR ||
           level == LogLevel_WARNING)
@@ -125,17 +174,39 @@
       }
       else if (level == LogLevel_INFO)
       {
-        return infoEnabled_;
+        return (infoCategoriesMask_ & category) != 0;
       }
       else if (level == LogLevel_TRACE)
       {
-        return traceEnabled_;
+        return (traceCategoriesMask_ & category) != 0;
       }
       else
       {
         return false;
       }
     }
+
+
+    LogCategory StringToCategory(const std::string& category)
+    {
+      if (category == "generic")
+      {
+        return LogCategory_GENERIC;
+      }
+      else if (category == "dicom")
+      {
+        return LogCategory_DICOM;
+      }
+      else if (category == "sqlite")
+      {
+        return LogCategory_SQLITE;
+      }
+      else
+      {
+        throw OrthancException(ErrorCode_ParameterOutOfRange,
+                               "Unknown log category: " + category);
+      }
+    }
   }
 }
 
@@ -247,7 +318,7 @@
     {
       std::string message = messageStream_.str();
 
-      if (IsLoggingEnabled(level_, category_))
+      if (IsCategoryEnabled(level_, category_))
       {
         switch (level_)
         {
@@ -637,7 +708,7 @@
         // We are logging using the Orthanc plugin SDK
 
         if (level == LogLevel_TRACE ||
-            !IsLoggingEnabled(level, category))
+            !IsCategoryEnabled(level, category))
         {
           // No trace level in plugins, directly exit as the stream is
           // set to "/dev/null"
@@ -653,7 +724,7 @@
       {
         // We are logging in a standalone application, not inside an Orthanc plugin
 
-        if (!IsLoggingEnabled(level, category))
+        if (!IsCategoryEnabled(level, category))
         {
           // This logging level is disabled, directly exit as the
           // stream is set to "/dev/null"
--- a/OrthancFramework/Sources/Logging.h	Mon Nov 02 17:15:57 2020 +0100
+++ b/OrthancFramework/Sources/Logging.h	Mon Nov 02 18:45:50 2020 +0100
@@ -52,11 +52,17 @@
       LogLevel_TRACE
     };
 
+    /**
+     * NB: The log level for each category is encoded as a bit
+     * mask. As a consequence, there can be up to 31 log categories
+     * (not 32, as the value GENERIC is reserved for the log commands
+     * that don't fall in a specific category).
+     **/
     enum LogCategory
     {
-      LogCategory_GENERIC,
-      LogCategory_SQLITE,
-      LogCategory_DICOM
+      LogCategory_GENERIC = (1 << 0),
+      LogCategory_SQLITE  = (1 << 1),
+      LogCategory_DICOM   = (1 << 2)
     };
     
     ORTHANC_PUBLIC const char* EnumerationToString(LogLevel level);
@@ -82,6 +88,15 @@
 
     ORTHANC_PUBLIC bool IsInfoLevelEnabled();
 
+    ORTHANC_PUBLIC void SetCategoryEnabled(LogLevel level,
+                                           LogCategory category,
+                                           bool enabled);
+
+    ORTHANC_PUBLIC bool IsCategoryEnabled(LogLevel level,
+                                          LogCategory category);
+    
+    ORTHANC_PUBLIC LogCategory StringToCategory(const std::string& category);
+
     ORTHANC_PUBLIC void SetTargetFile(const std::string& path);
 
     ORTHANC_PUBLIC void SetTargetFolder(const std::string& path);
--- a/OrthancFramework/UnitTestsSources/LoggingTests.cpp	Mon Nov 02 17:15:57 2020 +0100
+++ b/OrthancFramework/UnitTestsSources/LoggingTests.cpp	Mon Nov 02 18:45:50 2020 +0100
@@ -28,11 +28,11 @@
 #include <gtest/gtest.h>
 
 #include "../Sources/Logging.h"
+#include "../Sources/OrthancException.h"
 
 #include <boost/regex.hpp>
 #include <sstream>
 
-using namespace Orthanc::Logging;
 
 static std::stringstream testErrorStream;
 void TestError(const char* message)
@@ -133,7 +133,7 @@
 {
   LoggingMementoScope loggingConfiguration;
 
-  EnableTraceLevel(true);
+  Orthanc::Logging::EnableTraceLevel(true);
 
   typedef void(*LoggingFunctionFunc)(const char*);
 
@@ -146,7 +146,7 @@
   FuncStreamBuf<LoggingFunctionFunc> infoStreamBuf(TestInfo);
   std::ostream infoStream(&infoStreamBuf);
 
-  SetErrorWarnInfoLoggingStreams(errorStream, warningStream, infoStream);
+  Orthanc::Logging::SetErrorWarnInfoLoggingStreams(errorStream, warningStream, infoStream);
 
   {
     const char* text = "E is the set of all sets that do not contain themselves. Does E contain itself?";
@@ -196,4 +196,166 @@
     ASSERT_TRUE(ok);
     ASSERT_STREQ(payload.c_str(), text);
   }
+
+  Orthanc::Logging::EnableTraceLevel(false);  // Back to normal
 }
+
+
+
+TEST(Logging, Categories)
+{
+  using namespace Orthanc::Logging;
+  
+  // Unit tests are running in "--verbose" mode (not "--trace")
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_SQLITE));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_SQLITE));
+
+  // Cannot modify categories for ERROR and WARNING
+  ASSERT_THROW(SetCategoryEnabled(LogLevel_ERROR, LogCategory_GENERIC, true),
+               Orthanc::OrthancException);
+  ASSERT_THROW(SetCategoryEnabled(LogLevel_WARNING, LogCategory_GENERIC, false),
+               Orthanc::OrthancException);
+
+
+  EnableInfoLevel(false);
+  EnableTraceLevel(false);
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_FALSE(IsInfoLevelEnabled());
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_SQLITE));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_SQLITE));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_SQLITE));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_SQLITE));
+
+
+  // Test the "category" setters at INFO level
+  SetCategoryEnabled(LogLevel_INFO, LogCategory_DICOM, true);
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());   // At least one category is verbose
+  
+  SetCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC, true);
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  
+  SetCategoryEnabled(LogLevel_INFO, LogCategory_DICOM, false);
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());  // "GENERIC" is still verbose
+  
+  SetCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC, false);
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_FALSE(IsInfoLevelEnabled());
+
+
+  // Test the "category" setters at TRACE level
+  SetCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM, true);
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_TRUE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  
+  SetCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC, true);
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_TRUE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  
+  SetCategoryEnabled(LogLevel_INFO, LogCategory_DICOM, false);
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_TRUE(IsTraceLevelEnabled());  // "GENERIC" is still at trace level
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  
+  SetCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC, false);
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  
+  SetCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC, false);
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_FALSE(IsInfoLevelEnabled());
+
+
+
+  // Test the "macro" setters
+  EnableInfoLevel(true);
+  EnableTraceLevel(false);
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_SQLITE));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_SQLITE));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_SQLITE));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_SQLITE));
+
+  EnableInfoLevel(false);
+  EnableTraceLevel(true);  // "--trace" implies "--verbose"
+  ASSERT_TRUE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_ERROR, LogCategory_SQLITE));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_WARNING, LogCategory_SQLITE));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_SQLITE));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_GENERIC));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_DICOM));
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_SQLITE));
+
+
+
+  // Back to normal
+  EnableInfoLevel(true);
+  EnableTraceLevel(false);
+  ASSERT_FALSE(IsTraceLevelEnabled());
+  ASSERT_TRUE(IsInfoLevelEnabled());
+  ASSERT_TRUE(IsCategoryEnabled(LogLevel_INFO, LogCategory_SQLITE));
+  ASSERT_FALSE(IsCategoryEnabled(LogLevel_TRACE, LogCategory_SQLITE));
+}
--- a/OrthancServer/Sources/main.cpp	Mon Nov 02 17:15:57 2020 +0100
+++ b/OrthancServer/Sources/main.cpp	Mon Nov 02 18:45:50 2020 +0100
@@ -1495,6 +1495,18 @@
 }
 
 
+static void SetLoggingCategories(Logging::LogLevel level,
+                                 const std::string& lst)
+{
+  std::vector<std::string> categories;
+  Toolbox::TokenizeString(categories, lst, ':');
+  for (size_t i = 0; i < categories.size(); i++)
+  {
+    Logging::SetCategoryEnabled(level, Logging::StringToCategory(categories[i]), true);
+  }
+}
+
+
 static bool DisplayPerformanceWarning()
 {
   (void) DisplayPerformanceWarning;   // Disable warning about unused function
@@ -1563,10 +1575,18 @@
     {
       Logging::EnableTraceLevel(true);
     }
+    else if (boost::starts_with(argument, "--verbose="))  // New in Orthanc 1.8.1
+    {
+      SetLoggingCategories(Logging::LogLevel_INFO, argument.substr(10));
+    }
+    else if (boost::starts_with(argument, "--trace="))  // New in Orthanc 1.8.1
+    {
+      SetLoggingCategories(Logging::LogLevel_TRACE, argument.substr(8));
+    }
     else if (boost::starts_with(argument, "--logdir="))
     {
       // TODO WHAT IS THE ENCODING?
-      std::string directory = argument.substr(9);
+      const std::string directory = argument.substr(9);
 
       try
       {
@@ -1582,7 +1602,7 @@
     else if (boost::starts_with(argument, "--logfile="))
     {
       // TODO WHAT IS THE ENCODING?
-      std::string file = argument.substr(10);
+      const std::string file = argument.substr(10);
 
       try
       {