QPID-4651: C++ Broker add --log-disable option

Reviewed at https://reviews.apache.org/r/10799/



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

3 files changed, 164 insertions, 8 deletions

diff --git a/qpid/cpp/src/tests/BrokerFixture.h b/qpid/cpp/src/tests/BrokerFixture.h
index 92c6d22b57..4ce8315c15 100644
--- a/qpid/cpp/src/tests/BrokerFixture.h
+++ b/qpid/cpp/src/tests/BrokerFixture.h
@@ -51,6 +51,7 @@ struct  BrokerFixture : private boost::noncopyable {
         if (!::getenv("QPID_LOG_ENABLE") && !::getenv("QPID_TRACE")) {
             qpid::log::Options logOpts;
             logOpts.selectors.clear();
+            logOpts.deselectors.clear();
             logOpts.selectors.push_back("error+");
             qpid::log::Logger::instance().configure(logOpts);
         }
diff --git a/qpid/cpp/src/tests/dynamic_log_level_test b/qpid/cpp/src/tests/dynamic_log_level_test
index 534110e352..7548e40683 100755
--- a/qpid/cpp/src/tests/dynamic_log_level_test
+++ b/qpid/cpp/src/tests/dynamic_log_level_test
@@ -35,23 +35,56 @@ error() {
     exit 1;
 }
 
+checklog() {
+    if [[ $(grep echo $LOG_FILE | wc -l) -ne $1 ]]; then 
+        cat $LOG_FILE
+        error "Log contents not as expected - " $2
+    fi
+}
+
 rm -rf $LOG_FILE
 PORT=$($QPIDD_EXEC --auth=no --no-module-dir --daemon --port=0 --log-to-file $LOG_FILE) || error "Could not start broker"
 
 echo Broker for log level test started on $PORT, pid is $($QPIDD_EXEC --no-module-dir --check --port $PORT)
 
+# Set level to notice+ and send an echo request
+# The 'echo' in the log is hidden since it is at debug level.
 $srcdir/qpid-ctrl -b localhost:$PORT setLogLevel level='notice+' > /dev/null
 $srcdir/qpid-ctrl -b localhost:$PORT echo sequence=1 body=HIDDEN > /dev/null
+checklog 0 "Step 1 Expected no echo log entries"
+
+# Next, enable all Broker logs at debug and higher levels and send another echo
+# This 'echo' should be in the log.
 $srcdir/qpid-ctrl -b localhost:$PORT setLogLevel level='debug+:Broker' > /dev/null
 $srcdir/qpid-ctrl -b localhost:$PORT echo sequence=2 body=VISIBLE > /dev/null
-$srcdir/qpid-ctrl -b localhost:$PORT setLogLevel level='notice+' > /dev/null
+checklog 1 "Step 2 Expected one echo log entry"
 
-#check log includes debug statement for last echo, but not the first
-if [[ $(grep echo $LOG_FILE | wc -l) -ne 1 ]]; then 
-   cat $LOG_FILE
-   error "Log contents not as expected"
-else
-  rm -rf $LOG_FILE
-  echo OK
+# Now turn on Broker debug messages but specifically disable ManagementMethod logs
+# The 'echo' should be hidden.
+$srcdir/qpid-ctrl -b localhost:$PORT setLogLevel level='debug+:Broker !debug+:broker::Broker::ManagementMethod' > /dev/null
+$srcdir/qpid-ctrl -b localhost:$PORT echo sequence=3 body=HIDDEN > /dev/null
+checklog 1 "Step 3 Expected one echo log entry"
+
+# Verify that the management get returns what was just set
+$srcdir/qpid-ctrl -b localhost:$PORT getLogLevel > dynamic_log_level.tmp
+if [[ $(grep 'level=debug+:Broker,!debug+:broker::Broker::ManagementMethod' dynamic_log_level.tmp | wc -l) -ne 1 ]]; then
+    error "Step 4 getLogLevel returned unexpected value: " `cat dynamic_log_level.tmp`
 fi
+rm -rf dynamic_log_level.tmp
+
+cleanup
+
+# Start another broker with --log-disable settings and make sure the management string receives them
+rm -rf $LOG_FILE
+PORT=$($QPIDD_EXEC --auth=no --no-module-dir --daemon --port=0 --log-to-file $LOG_FILE --log-enable debug:foo --log-disable debug:bar) || error "Could not start broker"
+echo Broker for log level test started on $PORT, pid is $($QPIDD_EXEC --no-module-dir --check --port $PORT)
+
+$srcdir/qpid-ctrl -b localhost:$PORT getLogLevel > dynamic_log_level.tmp
+if [[ $(grep 'level=debug:foo,!debug:bar' dynamic_log_level.tmp | wc -l) -ne 1 ]]; then
+    error "Step 5 getLogLevel returned unexpected value: " `cat dynamic_log_level.tmp`
+fi
+rm -rf dynamic_log_level.tmp
+
+rm -rf $LOG_FILE
+echo OK
 
diff --git a/qpid/cpp/src/tests/logging.cpp b/qpid/cpp/src/tests/logging.cpp
index a29714c002..32cd09d73d 100644
--- a/qpid/cpp/src/tests/logging.cpp
+++ b/qpid/cpp/src/tests/logging.cpp
@@ -85,6 +85,17 @@ QPID_AUTO_TEST_CASE(testSelector_enable) {
     BOOST_CHECK(s.isEnabled(critical, "oops"));
 }
 
+QPID_AUTO_TEST_CASE(testSelector_disable) {
+    Selector s;
+    // Simple enable/disable
+    s.enable(trace,"foo");
+    BOOST_CHECK(s.isEnabled(trace,"foo"));
+    BOOST_CHECK(!s.isDisabled(trace,"foo"));
+    s.disable(trace,"foo");
+    BOOST_CHECK(s.isEnabled(trace,"foo"));
+    BOOST_CHECK(s.isDisabled(trace,"foo"));
+}
+
 QPID_AUTO_TEST_CASE(testStatementEnabled) {
     // Verify that the singleton enables and disables static
     // log statements.
@@ -271,6 +282,9 @@ QPID_AUTO_TEST_CASE(testOptionsParse) {
         "--log-enable", "error+:foo",
         "--log-enable", "debug:bar",
         "--log-enable", "info",
+        "--log-disable", "error+:foo",
+        "--log-disable", "debug:bar",
+        "--log-disable", "info",
         "--log-to-stderr", "no",
         "--log-to-file", "logout",
         "--log-level", "yes",
@@ -288,6 +302,7 @@ QPID_AUTO_TEST_CASE(testOptionsParse) {
     sinks = *opts.sinkOptions;
     vector<string> expect=list_of("error+:foo")("debug:bar")("info");
     BOOST_CHECK_EQUAL(expect, opts.selectors);
+    BOOST_CHECK_EQUAL(expect, opts.deselectors);
     BOOST_CHECK(!sinks.logToStderr);
     BOOST_CHECK(!sinks.logToStdout);
     BOOST_CHECK(sinks.logFile == "logout");
@@ -333,6 +348,64 @@ QPID_AUTO_TEST_CASE(testSelectorFromOptions) {
     BOOST_CHECK(s.isEnabled(critical, "foo"));
 }
 
+QPID_AUTO_TEST_CASE(testDeselectorFromOptions) {
+    const char* argv[]={
+        0,
+        "--log-disable", "error-:foo",
+        "--log-disable", "debug:bar",
+        "--log-disable", "info"
+    };
+    qpid::log::Options opts("");
+    opts.parse(ARGC(argv), const_cast<char**>(argv));
+    vector<string> expect=list_of("error-:foo")("debug:bar")("info");
+    BOOST_CHECK_EQUAL(expect, opts.deselectors);
+    Selector s(opts);
+    BOOST_CHECK(!s.isDisabled(warning, "x"));
+    BOOST_CHECK(!s.isDisabled(debug, "x"));
+    BOOST_CHECK(s.isDisabled(debug, "bar"));
+    BOOST_CHECK(s.isDisabled(trace, "foo"));
+    BOOST_CHECK(s.isDisabled(debug, "foo"));
+    BOOST_CHECK(s.isDisabled(info, "foo"));
+    BOOST_CHECK(s.isDisabled(notice, "foo"));
+    BOOST_CHECK(s.isDisabled(warning, "foo"));
+    BOOST_CHECK(s.isDisabled(error, "foo"));
+    BOOST_CHECK(!s.isDisabled(critical, "foo"));
+}
+
+QPID_AUTO_TEST_CASE(testMultiConflictingSelectorFromOptions) {
+    const char* argv[]={
+        0,
+        "--log-enable",  "trace+:foo",
+        "--log-disable", "error-:foo",
+        "--log-enable",  "debug:bar",
+        "--log-disable", "debug:bar",
+        "--log-enable",  "info",
+        "--log-disable", "info",
+        "--log-enable",  "debug+:Model",
+        "--log-disable", "info-:Model"
+    };
+    qpid::log::Options opts("");
+    opts.parse(ARGC(argv), const_cast<char**>(argv));
+    Selector s(opts);
+    BOOST_CHECK(!s.isEnabled(warning, "x", log::broker));
+    BOOST_CHECK(!s.isEnabled(debug, "x", log::broker));
+    BOOST_CHECK(!s.isEnabled(trace, "foo", log::broker));
+    BOOST_CHECK(!s.isEnabled(debug, "foo", log::broker));
+    BOOST_CHECK(!s.isEnabled(info, "foo", log::broker));
+    BOOST_CHECK(!s.isEnabled(notice, "foo", log::broker));
+    BOOST_CHECK(!s.isEnabled(warning, "foo", log::broker));
+    BOOST_CHECK(!s.isEnabled(error, "foo", log::broker));
+    BOOST_CHECK(s.isEnabled(critical, "foo", log::broker));
+    BOOST_CHECK(!s.isEnabled(debug, "bar", log::model));
+    BOOST_CHECK(!s.isEnabled(trace, "zaz", log::model));
+    BOOST_CHECK(!s.isEnabled(debug, "zaz", log::model));
+    BOOST_CHECK(!s.isEnabled(info, "zaz", log::model));
+    BOOST_CHECK(s.isEnabled(notice, "zaz", log::model));
+    BOOST_CHECK(s.isEnabled(warning, "zaz", log::model));
+    BOOST_CHECK(s.isEnabled(error, "zaz", log::model));
+    BOOST_CHECK(s.isEnabled(critical, "zaz", log::model));
+}
+
 QPID_AUTO_TEST_CASE(testLoggerStateure) {
     Logger& l=Logger::instance();
     ScopedSuppressLogging ls(l);
@@ -385,6 +458,55 @@ QPID_AUTO_TEST_CASE(testQuoteNonPrintable) {
     unlink("logging.tmp");
 }
 
+QPID_AUTO_TEST_CASE(testSelectorElements) {
+    SelectorElement s("debug");
+    BOOST_CHECK_EQUAL(s.levelStr, "debug");
+    BOOST_CHECK_EQUAL(s.patternStr, "");
+    BOOST_CHECK_EQUAL(s.level, debug);
+    BOOST_CHECK(!s.isDisable);
+    BOOST_CHECK(!s.isCategory);
+    BOOST_CHECK(!s.isLevelAndAbove);
+    BOOST_CHECK(!s.isLevelAndBelow);
+
+    SelectorElement t("debug:Broker");
+    BOOST_CHECK_EQUAL(t.levelStr, "debug");
+    BOOST_CHECK_EQUAL(t.patternStr, "Broker");
+    BOOST_CHECK_EQUAL(t.level, debug);
+    BOOST_CHECK_EQUAL(t.category, broker);
+    BOOST_CHECK(!t.isDisable);
+    BOOST_CHECK(t.isCategory);
+    BOOST_CHECK(!t.isLevelAndAbove);
+    BOOST_CHECK(!t.isLevelAndBelow);
+
+    SelectorElement u("info+:qmf::");
+    BOOST_CHECK_EQUAL(u.levelStr, "info");
+    BOOST_CHECK_EQUAL(u.patternStr, "qmf::");
+    BOOST_CHECK_EQUAL(u.level, info);
+    BOOST_CHECK(!u.isDisable);
+    BOOST_CHECK(!u.isCategory);
+    BOOST_CHECK(u.isLevelAndAbove);
+    BOOST_CHECK(!u.isLevelAndBelow);
+
+    SelectorElement v("critical-");
+    BOOST_CHECK_EQUAL(v.levelStr, "critical");
+    BOOST_CHECK_EQUAL(v.patternStr, "");
+    BOOST_CHECK_EQUAL(v.level, critical);
+    BOOST_CHECK(!v.isDisable);
+    BOOST_CHECK(!v.isCategory);
+    BOOST_CHECK(!v.isLevelAndAbove);
+    BOOST_CHECK(v.isLevelAndBelow);
+
+    SelectorElement w("!warning-:Management");
+    BOOST_CHECK_EQUAL(w.levelStr, "warning");
+    BOOST_CHECK_EQUAL(w.patternStr, "Management");
+    BOOST_CHECK_EQUAL(w.level, warning);
+    BOOST_CHECK_EQUAL(w.category, management);
+    BOOST_CHECK(w.isDisable);
+    BOOST_CHECK(w.isCategory);
+    BOOST_CHECK(!w.isLevelAndAbove);
+    BOOST_CHECK(w.isLevelAndBelow);
+}
+
 QPID_AUTO_TEST_SUITE_END()
 
 }} // namespace qpid::tests