QPID-3902 C++ Broker add log categories

svn merge --reintegrate from branch qpid/branches/qpid-3902/qpid



git-svn-id: https://svn.apache.org/repos/asf/qpid/trunk@1349006 13f79535-47bb-0310-9956-ffa450edef68

9 files changed, 292 insertions, 22 deletions

diff --git a/qpid/cpp/include/qpid/log/Logger.h b/qpid/cpp/include/qpid/log/Logger.h
index d255b7e150..9464fa52dd 100644
--- a/qpid/cpp/include/qpid/log/Logger.h
+++ b/qpid/cpp/include/qpid/log/Logger.h
@@ -36,7 +36,7 @@ namespace log {
 class QPID_COMMON_CLASS_EXTERN Logger : private boost::noncopyable {
   public:
     /** Flags indicating what to include in the log output */
-    enum FormatFlag { FILE=1, LINE=2, FUNCTION=4, LEVEL=8, TIME=16, THREAD=32, HIRES=64};
+    enum FormatFlag { FILE=1, LINE=2, FUNCTION=4, LEVEL=8, TIME=16, THREAD=32, HIRES=64, CATEGORY=128};
 
     /**
      * Logging output sink.
diff --git a/qpid/cpp/include/qpid/log/Options.h b/qpid/cpp/include/qpid/log/Options.h
index 17cbfde9bc..819f2c85f1 100644
--- a/qpid/cpp/include/qpid/log/Options.h
+++ b/qpid/cpp/include/qpid/log/Options.h
@@ -39,7 +39,7 @@ struct Options : public qpid::Options {
     std::string argv0;
     std::string name;
     std::vector<std::string> selectors;
-    bool time, level, thread, source, function, hiresTs;
+    bool time, level, thread, source, function, hiresTs, category;
     bool trace;
     std::string prefix;
     std::auto_ptr<SinkOptions> sinkOptions;
diff --git a/qpid/cpp/include/qpid/log/Selector.h b/qpid/cpp/include/qpid/log/Selector.h
index 061152d7e2..498d4a7342 100644
--- a/qpid/cpp/include/qpid/log/Selector.h
+++ b/qpid/cpp/include/qpid/log/Selector.h
@@ -35,17 +35,24 @@ struct Options;
 class Selector {
   public:
     /** Empty selector selects nothing */
-    Selector() {}
+    Selector() {
+        reset();
+    }
 
     /** Set selector from Options */
     QPID_COMMON_EXTERN Selector(const Options&);
 
     /** Equavlient to: Selector s; s.enable(l, s) */
     Selector(Level l, const std::string& s=std::string()) {
+        reset();
         enable(l,s);
     }
 
-    Selector(const std::string& enableStr) { enable(enableStr); }
+    Selector(const std::string& enableStr) {
+        reset();
+        enable(enableStr);
+    }
+
     /**
      * Enable messages with level in levels where the file
      * name contains substring. Empty string matches all.
@@ -54,14 +61,30 @@ class Selector {
         substrings[level].push_back(substring);
     }
 
+    /**
+     * Enable messages at this level for this category
+     */
+    void enable(Level level, Category category) {
+        catFlags[level][category] = true;
+    }
+
     /** Enable based on a 'level[+]:file' string */
     QPID_COMMON_EXTERN void enable(const std::string& enableStr);
 
     /** True if level is enabled for file. */
     QPID_COMMON_EXTERN bool isEnabled(Level level, const char* function);
+    QPID_COMMON_EXTERN bool isEnabled(Level level, const char* function, Category category);
+
+    /** Reset the category enable flags */
+    QPID_COMMON_EXTERN void reset() {
+        for (int lt = 0; lt < LevelTraits::COUNT; ++lt)
+            for (int ct = 0; ct < CategoryTraits::COUNT; ++ct)
+                catFlags[lt][ct] = false;
+    }
 
   private:
     std::vector<std::string> substrings[LevelTraits::COUNT];
+    bool catFlags[LevelTraits::COUNT][CategoryTraits::COUNT];
 };
 
 
diff --git a/qpid/cpp/include/qpid/log/Statement.h b/qpid/cpp/include/qpid/log/Statement.h
index 7b3ab60b81..610bfa077a 100644
--- a/qpid/cpp/include/qpid/log/Statement.h
+++ b/qpid/cpp/include/qpid/log/Statement.h
@@ -22,6 +22,7 @@
 #include "qpid/Msg.h"
 #include "qpid/CommonImportExport.h"
 #include <boost/current_function.hpp>
+#include <list>
 
 namespace qpid {
 namespace log {
@@ -55,15 +56,115 @@ struct LevelTraits {
     static const char* name(Level);
 };
 
-/** POD struct representing a logging statement in source code. */
+/** Formal message categories
+ * https://issues.apache.org/jira/browse/QPID-3902
+ *
+ * Category    Source code directory
+ * --------    ---------------------
+ * Security    acl ssl gssapi sasl cyrus
+ * Broker      broker
+ * Management  agent console qmf
+ * Amqp        amqp_0_10 framing
+ * System      log sys types xml thread mutex fork pipe time ...
+ * HA          cluster ha replication
+ * Messaging   messaging client
+ * Store       store
+ * IO          tcp rdma AsynchIO socket epoll
+ * Test
+ * Unspecified
+ */
+enum Category { security, broker, management, amqp, system, ha, messaging,
+    store, io, test, unspecified };
+struct CategoryTraits {
+    static const int COUNT=unspecified+1;
+
+    /** Test if given name is a Category name
+     */
+    static bool isCategory(const std::string& name);
+
+    /** Get category from string name
+     * @exception if name invalid.
+     */
+    static Category category(const char* name);
+
+    /** Get category from string name.
+     * @exception if name invalid.
+     */
+    static  Category category(const std::string& name) {
+        return category(name.c_str());
+    }
+
+    /** String name of category */
+    static const char* name(Category);
+};
+
+
+class CategoryFileNameHints {
+public:
+    CategoryFileNameHints(){
+        hintList.push_back(std::make_pair("AsynchIo",    io));
+        hintList.push_back(std::make_pair("TCP",         io));
+        hintList.push_back(std::make_pair("epoll",       io));
+        hintList.push_back(std::make_pair("Pollable",    io));
+        hintList.push_back(std::make_pair("Socket",      io));
+
+        hintList.push_back(std::make_pair("Sasl",        security));
+        hintList.push_back(std::make_pair("Ssl",         security));
+        hintList.push_back(std::make_pair("Acl",         security));
+        hintList.push_back(std::make_pair("acl",         security));
+        hintList.push_back(std::make_pair("cyrus",       security));
+
+        hintList.push_back(std::make_pair("amqp_",       amqp));
+        hintList.push_back(std::make_pair("framing",     amqp));
+
+        hintList.push_back(std::make_pair("management",  management));
+        hintList.push_back(std::make_pair("qmf",         management));
+        hintList.push_back(std::make_pair("console",     management));
+        hintList.push_back(std::make_pair("Management",  management));
+
+        hintList.push_back(std::make_pair("cluster",     ha));
+        hintList.push_back(std::make_pair("qpid/ha",     ha));
+        hintList.push_back(std::make_pair("qpid\\ha",    ha));
+        hintList.push_back(std::make_pair("replication", ha));
+        hintList.push_back(std::make_pair("ClusterSafe", ha));
+
+        hintList.push_back(std::make_pair("broker",      broker));
+        hintList.push_back(std::make_pair("SessionState",broker));
+        hintList.push_back(std::make_pair("DataDir",     broker));
+        hintList.push_back(std::make_pair("qpidd",       broker));
+        hintList.push_back(std::make_pair("xml",         broker));
+        hintList.push_back(std::make_pair("QpidBroker",  broker));
+
+        hintList.push_back(std::make_pair("store",       store));
+
+        hintList.push_back(std::make_pair("assert",      system));
+        hintList.push_back(std::make_pair("Exception",   system));
+        hintList.push_back(std::make_pair("sys",         system));
+        hintList.push_back(std::make_pair("SCM",         system));
+
+        hintList.push_back(std::make_pair("tests",       test));
+
+        hintList.push_back(std::make_pair("messaging",   messaging));
+        hintList.push_back(std::make_pair("types",       messaging));
+    }
+
+    static Category categoryOf(const char*const fName);
+
+private:
+    std::list<std::pair<const char* const, Category> > hintList;
+};
+
+ /** POD struct representing a logging statement in source code. */
 struct Statement {
     bool enabled;
     const char* file;
     int line;
     const char* function;
     Level level;
+    Category category;
 
     QPID_COMMON_EXTERN void log(const std::string& message);
+    QPID_COMMON_EXTERN static void categorize(Statement& s);
 
     struct Initializer {
         QPID_COMMON_EXTERN Initializer(Statement& s);
@@ -72,8 +173,14 @@ struct Statement {
 };
 
 ///@internal static initializer for a Statement.
-#define QPID_LOG_STATEMENT_INIT(level) \
-    { 0, __FILE__, __LINE__,  BOOST_CURRENT_FUNCTION, (::qpid::log::level) }
+#define QPID_LOG_STATEMENT_INIT_CAT(LEVEL, CATEGORY) \
+{ 0, __FILE__, __LINE__,  BOOST_CURRENT_FUNCTION, (::qpid::log::LEVEL), \
+(::qpid::log::CATEGORY) }
+
+
+///@internal static initializer for a Statement with unspecified category
+#define QPID_LOG_STATEMENT_INIT(LEVEL) \
+QPID_LOG_STATEMENT_INIT_CAT ( LEVEL , unspecified )
 
 /**
  * Like QPID_LOG but computes an additional boolean test expression
@@ -96,13 +203,26 @@ struct Statement {
     } while(0)
 
 /**
+ * Line QPID_LOG_IF but with the additional specification of a category.
+ * @param CATEGORY message category.
+ */
+#define QPID_LOG_IF_CAT(LEVEL, CATEGORY, TEST, MESSAGE)         \
+    do {                                                        \
+        using ::qpid::log::Statement;                           \
+        static Statement stmt_= QPID_LOG_STATEMENT_INIT_CAT(LEVEL, CATEGORY); \
+        static Statement::Initializer init_(stmt_);             \
+        if (stmt_.enabled && (TEST))                            \
+            stmt_.log(::qpid::Msg() << MESSAGE);                \
+    } while(0)
+
+/**
  * FLAG must be a boolean variable. Assigns FLAG to true iff logging
  * is enabled for LEVEL in the calling context.  Use when extra
  * support code is needed to generate log messages, to ensure that it
  * is only run if the logging level is enabled.
  * e.g.
  * bool logWarning;
- * QPID_LOG_TEST(LEVEL, logWarning);
+ * QPID_LOG_TEST(warning, logWarning);
  * if (logWarning) { do stuff needed for warning log messages }
  */
 #define QPID_LOG_TEST(LEVEL, FLAG)                              \
@@ -113,12 +233,31 @@ struct Statement {
         FLAG = stmt_.enabled;                                   \
     } while(0)
 
+    /**
+     * FLAG must be a boolean variable. Assigns FLAG to true iff logging
+     * is enabled for LEVEL in the calling context.  Use when extra
+     * support code is needed to generate log messages, to ensure that it
+     * is only run if the logging level is enabled.
+     * e.g.
+     * bool logWarning;
+     * QPID_LOG_TEST_CAT(warning, System, logWarning);
+     * if (logWarning) { do stuff needed for warning log messages }
+     */
+    #define QPID_LOG_TEST_CAT(LEVEL, CATEGORY, FLAG)                \
+    do {                                                        \
+        using ::qpid::log::Statement;                           \
+        static Statement stmt_= QPID_LOG_STATEMENT_INIT_CAT(LEVEL, CATEGORY); \
+        static Statement::Initializer init_(stmt_);             \
+        FLAG = stmt_.enabled;                                   \
+    } while(0)
+
 /**
  * Macro for log statements. Example of use:
  * @code
  * QPID_LOG(debug, "There are " << foocount << " foos in the bar.");
  * QPID_LOG(error, boost::format("Dohickey %s exploded") % dohicky.name());
  * @endcode
+ * Using QPID_LOG implies a category of Unspecified.
  *
  * You can subscribe to log messages by level, by component, by filename
  * or a combination @see Configuration.
@@ -130,6 +269,25 @@ struct Statement {
  */
 #define QPID_LOG(LEVEL, MESSAGE) QPID_LOG_IF(LEVEL, true, MESSAGE);
 
+/**
+ * Macro for log statements. Example of use:
+ * @code
+ * QPID_LOG_CAT(debug, System, "There are " << foocount << " foos in the bar.");
+ * QPID_LOG_CAT(error, System, boost::format("Dohickey %s exploded") % dohicky.name());
+ * @endcode
+ * Using QPID_LOG_CAT requires the specification of a category.
+ *
+ * You can subscribe to log messages by level, by component, by filename
+ * or a combination @see Configuration.
+ *
+ *@param LEVEL severity Level for message, should be one of:
+ * debug, info, notice, warning, error, critical. NB no qpid::log:: prefix.
+ *@param CATEGORY basic Category for the message.
+ *@param MESSAGE any object with an @eostream operator<<, or a sequence
+ * like of ostreamable objects separated by @e<<.
+ */
+#define QPID_LOG_CAT(LEVEL, CATEGORY, MESSAGE) QPID_LOG_IF_CAT(LEVEL, CATEGORY, true, MESSAGE);
+
 }} // namespace qpid::log
 
 
diff --git a/qpid/cpp/src/qpid/log/Logger.cpp b/qpid/cpp/src/qpid/log/Logger.cpp
index 800881c077..7c2e807ca9 100644
--- a/qpid/cpp/src/qpid/log/Logger.cpp
+++ b/qpid/cpp/src/qpid/log/Logger.cpp
@@ -47,7 +47,7 @@ using namespace std;
 typedef sys::Mutex::ScopedLock ScopedLock;
 
 inline void Logger::enable_unlocked(Statement* s) {
-    s->enabled=selector.isEnabled(s->level, s->function);
+    s->enabled=selector.isEnabled(s->level, s->function, s->category);
 }
 
 Logger& Logger::instance() {
@@ -95,6 +95,8 @@ void Logger::log(const Statement& s, const std::string& msg) {
         else
             qpid::sys::outputFormattedNow(os);
     }
+    if (flags&CATEGORY)
+        os << "[" << CategoryTraits::name(s.category) << "] ";
     if (flags&LEVEL)
         os << LevelTraits::name(s.level) << " ";
     if (flags&THREAD)
@@ -144,7 +146,8 @@ int Logger::format(const Options& opts) {
         bitIf(opts.source, (FILE|LINE)) |
         bitIf(opts.function, FUNCTION) |
         bitIf(opts.thread, THREAD) |
-        bitIf(opts.hiresTs, HIRES);
+        bitIf(opts.hiresTs, HIRES) |
+        bitIf(opts.category, CATEGORY);
     format(flags);
     return flags;
 }
diff --git a/qpid/cpp/src/qpid/log/Options.cpp b/qpid/cpp/src/qpid/log/Options.cpp
index 1259244297..10422bbb1e 100644
--- a/qpid/cpp/src/qpid/log/Options.cpp
+++ b/qpid/cpp/src/qpid/log/Options.cpp
@@ -39,6 +39,7 @@ Options::Options(const std::string& argv0_, const std::string& name_) :
     source(false),
     function(false),
     hiresTs(false),
+    category(true),
     trace(false),
     sinkOptions (SinkOptions::create(argv0_))
 {
@@ -49,15 +50,23 @@ Options::Options(const std::string& argv0_, const std::string& name_) :
     for (int i = 1; i < LevelTraits::COUNT; ++i)
         levels << " " << LevelTraits::name(Level(i));
 
+    ostringstream categories;
+    categories << CategoryTraits::name(Category(0));
+    for (int i = 1; i < CategoryTraits::COUNT; ++i)
+        categories << " " << CategoryTraits::name(Category(i));
+
     addOptions()
         ("trace,t", optValue(trace), "Enables all logging" )
         ("log-enable", optValue(selectors, "RULE"),
-         ("Enables logging for selected levels and components. " 
+         ("Enables logging for selected levels and components. "
           "RULE is in the form 'LEVEL[+][:PATTERN]' "
-          "Levels are one of: \n\t "+levels.str()+"\n"
+          "LEVEL is one of: \n\t "+levels.str()+"\n"
+          "PATTERN is a function name or a catogory: \n\t "+categories.str()+"\n"
           "For example:\n"
           "\t'--log-enable warning+' "
           "logs all warning, error and critical messages.\n"
+          "\t'--log-enable trace+:Broker' "
+          "logs all category 'Broker' messages.\n"
           "\t'--log-enable debug:framing' "
           "logs debug messages from the framing namespace. "
           "This option can be used multiple times").c_str())
@@ -67,6 +76,7 @@ Options::Options(const std::string& argv0_, const std::string& name_) :
         ("log-thread", optValue(thread,"yes|no"), "Include thread ID in log messages")
         ("log-function", optValue(function,"yes|no"), "Include function signature in log messages")
         ("log-hires-timestamp", optValue(hiresTs,"yes|no"), "Use hi-resolution timestamps in log messages")
+        ("log-category", optValue(category,"yes|no"), "Include category in log messages")
         ("log-prefix", optValue(prefix,"STRING"), "Prefix to append to all log messages")
         ;
     add(*sinkOptions);
@@ -83,6 +93,7 @@ Options::Options(const Options &o) :
     source(o.source),
     function(o.function),
     hiresTs(o.hiresTs),
+    category(o.category),
     trace(o.trace),
     prefix(o.prefix),
     sinkOptions (SinkOptions::create(o.argv0))
@@ -101,11 +112,12 @@ Options& Options::operator=(const Options& x) {
         source = x.source;
         function = x.function;
         hiresTs = x.hiresTs;
+        category = x.category;
         trace = x.trace;
         prefix = x.prefix;
         *sinkOptions = *x.sinkOptions;
     }
     return *this;
 }
-        
+
 }} // namespace qpid::log
diff --git a/qpid/cpp/src/qpid/log/Selector.cpp b/qpid/cpp/src/qpid/log/Selector.cpp
index a4bc580470..8757486d88 100644
--- a/qpid/cpp/src/qpid/log/Selector.cpp
+++ b/qpid/cpp/src/qpid/log/Selector.cpp
@@ -37,18 +37,29 @@ void Selector::enable(const string& enableStr) {
         level=enableStr.substr(0,c);
         pattern=enableStr.substr(c+1);
     }
+    bool isCat = CategoryTraits::isCategory(pattern);
     if (!level.empty() && level[level.size()-1]=='+') {
         for (int i =  LevelTraits::level(level.substr(0,level.size()-1));
              i < LevelTraits::COUNT;
-             ++i)
-            enable(Level(i), pattern);
+             ++i) {
+            if (isCat) {
+                enable(Level(i), CategoryTraits::category(pattern));
+            } else {
+                enable(Level(i), pattern);
+            }
+        }
     }
     else {
-        enable(LevelTraits::level(level), pattern);
+        if (isCat) {
+            enable(LevelTraits::level(level), CategoryTraits::category(pattern));
+        } else {
+            enable(LevelTraits::level(level), pattern);
+        }
     }
 }
 
 Selector::Selector(const Options& opt){
+    reset();
     for_each(opt.selectors.begin(), opt.selectors.end(),
              boost::bind(&Selector::enable, this, _1));
 }
@@ -58,11 +69,17 @@ bool Selector::isEnabled(Level level, const char* function) {
     for (std::vector<std::string>::iterator i=substrings[level].begin();
          i != substrings[level].end();
          ++i)
-    {
-        if (std::search(function, functionEnd, i->begin(), i->end()) != functionEnd)
-            return true;
-    }
+        {
+            if (std::search(function, functionEnd, i->begin(), i->end()) != functionEnd)
+                return true;
+        }
     return false;
 }
 
+bool Selector::isEnabled(Level level, const char* function, Category category) {
+    if (catFlags[level][category])
+        return true;
+    return isEnabled(level, function);
+}
+
 }} // namespace qpid::log
diff --git a/qpid/cpp/src/qpid/log/Statement.cpp b/qpid/cpp/src/qpid/log/Statement.cpp
index 09d1c9449f..56ee581c80 100644
--- a/qpid/cpp/src/qpid/log/Statement.cpp
+++ b/qpid/cpp/src/qpid/log/Statement.cpp
@@ -50,10 +50,42 @@ std::string quote(const std::string& str) {
 }
 }
 
+//
+// Instance of name hints
+//
+static CategoryFileNameHints filenameHints;
+
+
+Category CategoryFileNameHints::categoryOf(const char* const fName) {
+    for (std::list<std::pair<const char* const, Category> >::iterator
+           it  = filenameHints.hintList.begin();
+           it != filenameHints.hintList.end();
+         ++it) {
+        if (strstr(fName, (const char* const)it->first) != 0) {
+            return it->second;
+        }
+    }
+    return unspecified;
+}
+
+
+void Statement::categorize(Statement& s) {
+    // given a statement and it's category
+    // if the category is Unspecified then try to find a
+    // better category based on the path and file name.
+    if (s.category == log::unspecified) {
+        s.category = CategoryFileNameHints::categoryOf(s.file);
+    } else {
+        // already has a category so leave it alone
+    }
+}
+
+
 void Statement::log(const std::string& message) {
     Logger::instance().log(*this, quote(message));
 }
 
+
 Statement::Initializer::Initializer(Statement& s) : statement(s) {
     // QPID-3891
     // From the given BOOST_CURRENT_FUNCTION name extract only the
@@ -99,16 +131,22 @@ Statement::Initializer::Initializer(Statement& s) : statement(s) {
         // no function-name pointer to process
     }
 
+    Statement::categorize(s);
     Logger::instance().add(s);
 }
 
+
 namespace {
 const char* names[LevelTraits::COUNT] = {
     "trace", "debug", "info", "notice", "warning", "error", "critical"
 };
 
-} // namespace
+const char* catNames[CategoryTraits::COUNT] = {
+    "Security", "Broker", "Management", "Amqp", "System", "HA", "Messaging",
+    "Store", "IO", "Test", "Unspecified"
+};
 
+} // namespace
 Level LevelTraits::level(const char* name) {
     for (int i =0; i < LevelTraits::COUNT; ++i) {
         if (strcmp(names[i], name)==0)
@@ -121,4 +159,23 @@ const char* LevelTraits::name(Level l) {
     return names[l];
 }
 
+bool CategoryTraits::isCategory(const std::string& name) {
+    for (int i =0; i < CategoryTraits::COUNT; ++i) {
+        if (strcmp(catNames[i], name.c_str())==0)
+            return true;
+    }
+    return false;
+}
+
+Category CategoryTraits::category(const char* name) {
+    for (int i =0; i < CategoryTraits::COUNT; ++i) {
+        if (strcmp(catNames[i], name)==0)
+            return Category(i);
+    }
+    throw std::runtime_error(std::string("Invalid log category name: ")+name);
+}
+
+const char* CategoryTraits::name(Category c) {
+    return catNames[c];
+}
 }} // namespace qpid::log
diff --git a/qpid/cpp/src/tests/logging.cpp b/qpid/cpp/src/tests/logging.cpp
index 5d5bb1feef..47e601ed05 100644
--- a/qpid/cpp/src/tests/logging.cpp
+++ b/qpid/cpp/src/tests/logging.cpp
@@ -258,7 +258,7 @@ QPID_AUTO_TEST_CASE(testOverhead) {
 Statement statement(
     Level level, const char* file="", int line=0, const char* fn=0)
 {
-    Statement s={0, file, line, fn, level};
+    Statement s={0, file, line, fn, level, ::qpid::log::unspecified};
     return s;
 }