Mailing-List: contact commits-help@qpid.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@qpid.apache.org
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Subject: svn commit: r1650130 - in /qpid/dispatch/trunk:
 python/qpid_dispatch/management/qdrouter.json
 python/qpid_dispatch_internal/management/agent.py src/log.c
 tests/system_test.py tests/system_tests_management.py tests/threads4.conf
Date: Wed, 07 Jan 2015 18:03:30 -0000
To: commits@qpid.apache.org
From: aconway@apache.org
Message-Id: <20150107180330.C28F9AC003E@hades.apache.org>

Author: aconway
Date: Wed Jan  7 18:03:30 2015
New Revision: 1650130

URL: http://svn.apache.org/r1650130
Log:
DISPATCH-92: Make dispatch logging configuration more flexible and qpid-like

NOTE: this is an incompatble change to the management and configuration schema.
Replace log configuration "level: x" by "enable: x+"

Replaced log "level" attribute with "enable" to set logging level.

Levels are: trace, debug, info, notice, warning, error, critical. The enable
string is a comma-separated list of levels. A level may have a trailing '+' to
enable that level and above. For example 'trace,debug,warning+' means enable
trace, debug, warning, error and critical. The value 'none' means disable
logging for the module. The value 'default' means use the value from the DEFAULT
module.

Modified:
    qpid/dispatch/trunk/python/qpid_dispatch/management/qdrouter.json
    qpid/dispatch/trunk/python/qpid_dispatch_internal/management/agent.py
    qpid/dispatch/trunk/src/log.c
    qpid/dispatch/trunk/tests/system_test.py
    qpid/dispatch/trunk/tests/system_tests_management.py
    qpid/dispatch/trunk/tests/threads4.conf

Modified: qpid/dispatch/trunk/python/qpid_dispatch/management/qdrouter.json
URL: http://svn.apache.org/viewvc/qpid/dispatch/trunk/python/qpid_dispatch/management/qdrouter.json?rev=1650130&r1=1650129&r2=1650130&view=diff
==============================================================================
--- qpid/dispatch/trunk/python/qpid_dispatch/management/qdrouter.json (original)
+++ qpid/dispatch/trunk/python/qpid_dispatch/management/qdrouter.json Wed Jan  7 18:03:30 2015
@@ -253,7 +253,7 @@
         },
 
         "log": {
-            "description": "Set the level of logging output from a particular module.",
+            "description": "Configure logging for a particular module.",
             "extends": "configurationEntity",
             "operations": ["CREATE", "READ", "UPDATE"],
             "attributes": {
@@ -265,25 +265,18 @@
                         "AGENT",
                         "CONTAINER",
                         "CONFIG",
-                        "DEFAULT",
                         "ERROR",
-                        "DISPATCH"
+                        "DISPATCH",
+                        "DEFAULT"
                     ],
                     "required": true,
-                    "description": "Module to configure logging level. The special module 'DEFAULT' specifies logging defaults for modules that don't have explicit log configuration."
+                    "description": "Module to configure. The special module 'DEFAULT' specifies defaults for all modules."
                 },
-                "level": {
-                    "type": [
-                        "none",
-                        "trace",
-                        "debug",
-                        "info",
-                        "notice",
-                        "warning",
-                        "error",
-                        "critical"
-                    ],
-                    "description": "Indicates the minimum logging level for the module. E.g. 'warning' means log warning, error and critical messages. 'trace' logs all messages. 'none' disables logging for the module."
+                "enable": {
+                    "type": "String",
+                    "default": "default",
+                    "required": true,
+                    "description": "Levels are: trace, debug, info, notice, warning, error, critical. The enable string is a comma-separated list of levels. A level may have a trailing '+' to enable that level and above. For example 'trace,debug,warning+' means enable trace, debug, warning, error and critical. The value 'none' means disable logging for the module. The value 'default' means use the value from the DEFAULT module."
                 },
                 "timestamp": {
                     "type": "Boolean",

Modified: qpid/dispatch/trunk/python/qpid_dispatch_internal/management/agent.py
URL: http://svn.apache.org/viewvc/qpid/dispatch/trunk/python/qpid_dispatch_internal/management/agent.py?rev=1650130&r1=1650129&r2=1650130&view=diff
==============================================================================
--- qpid/dispatch/trunk/python/qpid_dispatch_internal/management/agent.py (original)
+++ qpid/dispatch/trunk/python/qpid_dispatch_internal/management/agent.py Wed Jan  7 18:03:30 2015
@@ -196,7 +196,7 @@ class LogEntity(AgentEntity):
     def __init__(self, agent, entity_type, attributes=None, validate=True):
         # Special defaults for DEFAULT module. 
         if attributes.get("module") == "DEFAULT":
-            defaults = dict(level="info", timestamp=True, source=False, output="stderr")
+            defaults = dict(enable="info+", timestamp=True, source=False, output="stderr")
             attributes = dict(defaults, **attributes)
         super(LogEntity, self).__init__(agent, entity_type, attributes, validate=True)
 

Modified: qpid/dispatch/trunk/src/log.c
URL: http://svn.apache.org/viewvc/qpid/dispatch/trunk/src/log.c?rev=1650130&r1=1650129&r2=1650130&view=diff
==============================================================================
--- qpid/dispatch/trunk/src/log.c (original)
+++ qpid/dispatch/trunk/src/log.c Wed Jan  7 18:03:30 2015
@@ -146,17 +146,22 @@ static sys_mutex_t          *log_lock =
 static sys_mutex_t          *log_source_lock = 0;
 static qd_log_source_list_t  source_list = {0};
 
-typedef enum {NONE, TRACE, DEBUG, INFO, NOTICE, WARNING, ERROR, CRITICAL, N_LEVELS} level_index_t;
-typedef struct level {
+typedef enum {DEFAULT, NONE, TRACE, DEBUG, INFO, NOTICE, WARNING, ERROR, CRITICAL, N_LEVELS} level_index_t;
+
+typedef struct level_t {
     const char* name;
     int bit;     // QD_LOG bit
     int mask;    // Bit or higher
     const int syslog;
-} level;
+} level_t;
+
 #define ALL_BITS (QD_LOG_CRITICAL | (QD_LOG_CRITICAL-1))
+
 #define LEVEL(name, QD_LOG, SYSLOG) { name, QD_LOG,  ALL_BITS & ~(QD_LOG-1), SYSLOG }
-static level levels[] = {
-    {"none", 0, -1, 0},
+
+static level_t levels[] = {
+    {"default", -1, -1, 0},
+    {"none", 0, 0, 0},
     LEVEL("trace",    QD_LOG_TRACE, LOG_DEBUG), /* syslog has no trace level */
     LEVEL("debug",    QD_LOG_DEBUG, LOG_DEBUG),
     LEVEL("info",     QD_LOG_INFO, LOG_INFO),
@@ -165,29 +170,53 @@ static level levels[] = {
     LEVEL("error",    QD_LOG_ERROR, LOG_ERR),
     LEVEL("critical", QD_LOG_CRITICAL, LOG_CRIT)
 };
+
 static const char level_names[TEXT_MAX]; /* Set up in qd_log_initialize */
 
-static const level* level_for_bit(int bit) {
+/// Return NULL and set qd_error if not a valid bit.
+static const level_t* level_for_bit(int bit) {
     level_index_t i = 0;
     while (i < N_LEVELS && levels[i].bit != bit) ++i;
     if (i == N_LEVELS) {
-        qd_log(logging_log_source, QD_LOG_ERROR, "'%d' is not a valid log level bit. Defaulting to %s", bit, levels[INFO].name);
-        i = INFO;
-        assert(0);
+        qd_error(QD_ERROR_CONFIG, "'%d' is not a valid log level bit.", bit);
+        return NULL;
     }
     return &levels[i];
 }
 
-static const level* level_for_name(const char *name) {
+/// Return NULL and set qd_error if not a valid level.
+static const level_t* level_for_name(const char *name, int len) {
     level_index_t i = 0;
-    while (i < N_LEVELS && strcasecmp(levels[i].name, name) != 0) ++i;
+    while (i < N_LEVELS && strncasecmp(levels[i].name, name, len) != 0) ++i;
     if (i == N_LEVELS) {
-        qd_log(logging_log_source, QD_LOG_ERROR, "'%s' is not a valid log level. Should be one of {%s}. Defaulting to %s", name, level_names, levels[INFO].name);
-        i = INFO;
+        qd_error(QD_ERROR_CONFIG, "'%s' is not a valid log level. Should be one of {%s}.",
+                 name, level_names);
+        return NULL;
     }
     return &levels[i];
 }
 
+static const char *SEPARATORS=", ;:";
+
+/// Calculate the bit mask for a log enable string. Return -1 and set qd_error on error.
+static int enable_mask(const char *enable_) {
+    char enable[strlen(enable_)+1]; /* Non-const copy for strtok */
+    strcpy(enable, enable_);
+    char *saveptr = 0;
+    int mask = 0;
+    for (const char *token = strtok_r(enable, SEPARATORS, &saveptr);
+         token;
+         token = strtok_r(NULL, SEPARATORS, &saveptr))
+    {
+        int len = strlen(token);
+        int plus = (len > 0 && token[len-1] == '+') ? 1 : 0;
+        const level_t* level = level_for_name(token, len-plus);
+        if (!level) return -1;  /* qd_error already set */
+        mask |= (plus ? level->mask : level->bit);
+    }
+    return mask;
+}
+
 /// Caller must hold log_source_lock
 static qd_log_source_t* lookup_log_source_lh(const char *module)
 {
@@ -211,6 +240,12 @@ static void write_log(qd_log_source_t *l
     char *begin = log_str;
     char *end = log_str + LOG_MAX;
 
+    const level_t *level = level_for_bit(entry->level);
+    if (!level) {
+        level = &levels[INFO];
+        qd_error_clear();
+    }
+
     if (default_bool(log_source->timestamp, default_log_source->timestamp)) {
         char buf[100];
         buf[0] = '\0';
@@ -218,7 +253,7 @@ static void write_log(qd_log_source_t *l
         buf[strlen(buf)-1] = '\0'; /* Get rid of trailng \n */
         aprintf(&begin, end, "%s ", buf);
     }
-    aprintf(&begin, end, "%s (%s) %s", entry->module, level_for_bit(entry->level)->name, entry->text);
+    aprintf(&begin, end, "%s (%s) %s", entry->module, level->name, entry->text);
     if (default_bool(log_source->source, default_log_source->source))
         aprintf(&begin, end, " (%s:%d)", entry->file, entry->line);
     aprintf(&begin, end, "\n");
@@ -233,7 +268,7 @@ static void write_log(qd_log_source_t *l
         fflush(sink->file);
     }
     if (sink->syslog) {
-        int syslog_level = level_for_bit(entry->level)->syslog;
+        int syslog_level = level->syslog;
         if (syslog_level != -1)
             syslog(syslog_level, "%s", log_str);
     }
@@ -361,10 +396,10 @@ qd_error_t qd_log_entity(qd_entity_t *en
     sys_mutex_unlock(log_source_lock);
     free(module);
 
-    if (qd_entity_has(entity, "level")) {
-        char *level = qd_entity_get_string(entity, "level");
-        copy.mask = level_for_name(level)->mask;
-        free(level);
+    if (qd_entity_has(entity, "enable")) {
+        char *enable = qd_entity_get_string(entity, "enable");
+        copy.mask = enable_mask(enable);
+        free(enable);
     }
     QD_ERROR_RET();
 

Modified: qpid/dispatch/trunk/tests/system_test.py
URL: http://svn.apache.org/viewvc/qpid/dispatch/trunk/tests/system_test.py?rev=1650130&r1=1650129&r2=1650130&view=diff
==============================================================================
--- qpid/dispatch/trunk/tests/system_test.py (original)
+++ qpid/dispatch/trunk/tests/system_test.py Wed Jan  7 18:03:30 2015
@@ -323,7 +323,7 @@ class Qdrouterd(Process):
         self.config = copy(config)
         if not [l for l in config if l[0] == 'log']:
             config.append(
-                ('log', {'module':'DEFAULT', 'level':'trace', 'source': 'true', 'output':name+'.log'}))
+                ('log', {'module':'DEFAULT', 'enable':'trace+', 'source': 'true', 'output':name+'.log'}))
         if not pyinclude and os.environ['QPID_DISPATCH_HOME']:
             pyinclude = os.path.join(os.environ['QPID_DISPATCH_HOME'], 'python')
         super(Qdrouterd, self).__init__(

Modified: qpid/dispatch/trunk/tests/system_tests_management.py
URL: http://svn.apache.org/viewvc/qpid/dispatch/trunk/tests/system_tests_management.py?rev=1650130&r1=1650129&r2=1650130&view=diff
==============================================================================
--- qpid/dispatch/trunk/tests/system_tests_management.py (original)
+++ qpid/dispatch/trunk/tests/system_tests_management.py Wed Jan  7 18:03:30 2015
@@ -138,7 +138,7 @@ class ManagementTest(system_test.TestCas
         default = self.node.read(identity='log/DEFAULT')
         self.assertEqual(default.attributes,
                          {u'identity': u'log/DEFAULT',
-                          u'level': u'trace',
+                          u'enable': u'trace+',
                           u'module': u'DEFAULT',
                           u'name': u'log/DEFAULT',
                           u'output': u'ManagementTest.log',
@@ -147,23 +147,52 @@ class ManagementTest(system_test.TestCas
                           u'type': u'org.apache.qpid.dispatch.log'})
 
 
-        def check_log(log, bad_type='nosuch'):
-            # Cause an error and verify it shows up in the log file.
+        def check_log(log, error=True, debug=False):
+            """Cause an error and check for expected error and debug logs"""
+            bad_type = "nosuch"
             self.assertRaises(ManagementError, self.node.create, type=bad_type, name=bad_type)
             f = self.cleanup(open(log))
             logstr = f.read()
-            self.assertTrue(re.search(r'ValidationError.*%s' % bad_type, logstr),
-                            msg="Can't find expected ValidationError.*%s in '%r'" % (bad_type, logstr))
+            def assert_expected(expect, regex, logstr):
+                match = re.search(regex, logstr)
+                assert bool(expect) == bool(match), "%s %s:\n%s" % (
+                    ((match and "Found") or "Not found"), regex, logstr)
+            assert_expected(error, r'AGENT \(error\).*%s' % bad_type, logstr)
+            assert_expected(debug, r'AGENT \(debug\)', logstr)
 
-        # Create a log entity, verify logging is as expected
-        log = os.path.abspath("test_log.log")
-        self.node.update(dict(level="error", output=log), name="log/AGENT")
-        check_log(log)
-
-        # Update the log entity to output to a different file
-        log = os.path.abspath("test_log2.log")
-        self.node.update(dict(level="error", output=log), identity='log/AGENT')
-        check_log(log)
+        log_count = [0]         # In list to work-around daft python scoping rules.
+
+        def update_check_log(attributes, error=True, debug=False):
+            log_count[0] += 1
+            log = os.path.abspath("test_log.log%s" % log_count[0])
+            attributes["output"] = log
+            attributes["identity"] = "log/AGENT"
+            self.node.update(attributes)
+            check_log(log, error, debug)
+
+        # Expect error but no debug
+        update_check_log(dict(enable="warning+"))
+        update_check_log(dict(enable="error"))
+        update_check_log(dict(enable="TRACE , Error info")) # Case and space insensitive
+
+        # Expect no error if not enabled.
+        update_check_log(dict(enable="info,critical"), error=False)
+        update_check_log(dict(enable="none"), error=False)
+        update_check_log(dict(enable=""), error=False)
+
+        # Expect debug
+        update_check_log(dict(enable="Debug"), error=False, debug=True)
+        update_check_log(dict(enable="trace+"), debug=True)
+
+        # Check defaults are picked up
+        update_check_log(dict(enable="default"), error=True, debug=True)
+        self.node.update(dict(identity="log/DEFAULT", enable="debug"))
+        update_check_log(dict(enable="DEFAULT"), error=False, debug=True)
+        self.node.update(dict(identity="log/DEFAULT", enable="error"))
+        update_check_log(dict(enable="default"), error=True, debug=False)
+
+        # Invalid values
+        self.assertRaises(ManagementError, self.node.update, dict(identity="log/AGENT", enable="foo"))
 
     def test_create_fixed_address(self):
         self.assert_create_ok(FIXED_ADDRESS, 'fixed1', dict(prefix='fixed1'))

Modified: qpid/dispatch/trunk/tests/threads4.conf
URL: http://svn.apache.org/viewvc/qpid/dispatch/trunk/tests/threads4.conf?rev=1650130&r1=1650129&r2=1650130&view=diff
==============================================================================
--- qpid/dispatch/trunk/tests/threads4.conf (original)
+++ qpid/dispatch/trunk/tests/threads4.conf Wed Jan  7 18:03:30 2015
@@ -26,5 +26,5 @@ container {
 }
 log {
     module: DEFAULT
-    level: debug
+    enable: debug+
 }


---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@qpid.apache.org
For additional commands, e-mail: commits-help@qpid.apache.org