changeset 811:f3c72548d96e

Fix logging subsystem of thermostat. This patch fixes LoggingUtils and hence thermostat logging subsystem. Previously logging settings made the assumption that log handlers are added via LogManager.getLogManager().readConfiguration(fis), which it doesn't do. This has been fixed and a small test for LoggingUtils has been added to make sure this keeps working. Note that I've set the default log level in distribution/config/logging.properties to FINEST. This will make thermostat fairly chatty, but I think it's a good idea to do this now since it might reveal problems which we were not previously seeing. If you wish, this can be overruled by setting the level to something higher in file ~/.thermostat/logging.properties (see patch for syntax). As a follow-up patch, I'll go through the code and will change Logger.getLogger() to LoggingUtils.getLogger() which should fix logging entirely. I should also note that with the --logLevel CLI option there exists a bit of a chicken-and-egg problem. Any vigilant user will notice that something like: $ ./bin/thermostat agent --logLevel WARNING -d mongodb://127.0.0.1:27518 will produce two messages of level INFO. This is due to the fact that the --logLevel argument is parsed in LauncherImpl i.e. after said class got instantiated. The logging system is set up (from config files) before this. When LauncherImpl is instantiated. Now, we do log things in Activators but the log level based on the CLI argument is set later. I.e. after some bundles are activated. That's where these INFO messages come from. One cannot un-log things :) Reviewed-by: neugens Review-thread: http://icedtea.classpath.org/pipermail/thermostat/2012-November/004330.html
author Severin Gehwolf <sgehwolf@redhat.com>
date Thu, 29 Nov 2012 18:11:52 +0100
parents e5ff501704ab
children 7d6bdce41bcf
files agent/command/src/main/java/com/redhat/thermostat/agent/command/internal/Activator.java common/core/src/main/java/com/redhat/thermostat/common/utils/LoggingUtils.java common/core/src/test/java/com/redhat/thermostat/common/utils/LoggingUtilsTest.java common/core/src/test/resources/globalLogging.properties common/core/src/test/resources/userLogging.properties distribution/config/logging.properties unix-process-handler/src/main/java/com/redhat/thermostat/service/activator/Activator.java
diffstat 7 files changed, 278 insertions(+), 9 deletions(-) [+]
line wrap: on
line diff
--- a/agent/command/src/main/java/com/redhat/thermostat/agent/command/internal/Activator.java	Thu Nov 29 17:06:15 2012 -0500
+++ b/agent/command/src/main/java/com/redhat/thermostat/agent/command/internal/Activator.java	Thu Nov 29 18:11:52 2012 +0100
@@ -45,10 +45,11 @@
 
 import com.redhat.thermostat.agent.command.ConfigurationServer;
 import com.redhat.thermostat.agent.command.ReceiverRegistry;
+import com.redhat.thermostat.common.utils.LoggingUtils;
 
 public class Activator implements BundleActivator {
 
-    private static final Logger logger = Logger.getLogger(Activator.class.getSimpleName());
+    private static final Logger logger = LoggingUtils.getLogger(Activator.class);
 
     private ServiceRegistration confServerRegistration;
     private ReceiverRegistry receivers;
--- a/common/core/src/main/java/com/redhat/thermostat/common/utils/LoggingUtils.java	Thu Nov 29 17:06:15 2012 -0500
+++ b/common/core/src/main/java/com/redhat/thermostat/common/utils/LoggingUtils.java	Thu Nov 29 18:11:52 2012 +0100
@@ -39,6 +39,7 @@
 import java.io.File;
 import java.io.FileInputStream;
 import java.io.IOException;
+import java.util.Properties;
 import java.util.logging.ConsoleHandler;
 import java.util.logging.Handler;
 import java.util.logging.Level;
@@ -57,8 +58,14 @@
  */
 public final class LoggingUtils {
 
-    private static Logger root = null;
-    private static final String ROOTNAME = "com.redhat.thermostat";
+    // package private for testing
+    static Logger root = null;
+    // package private for testing
+    static final String ROOTNAME = "com.redhat.thermostat";
+    private static final String HANDLER_PROP = ROOTNAME + ".handlers";
+    private static final String LOG_LEVEL_PROP = ROOTNAME + ".level";
+    private static final String DEFAULT_LOG_HANDLER = "java.util.logging.ConsoleHandler";
+    private static final Level DEFAULT_LOG_LEVEL = Level.INFO;
 
     private LoggingUtils() {
         /* should not be instantiated */
@@ -114,14 +121,18 @@
     public static void loadGlobalLoggingConfig() throws InvalidConfigurationException {
         File thermostatEtcDir = new File(ConfigUtils.getThermostatHome(), "etc");
         File loggingPropertiesFile = new File(thermostatEtcDir, "logging.properties");
-        if (loggingPropertiesFile.isFile()) {
-            readLoggingProperties(loggingPropertiesFile);
-        }
+        loadConfig(loggingPropertiesFile);
     }
+    
 
     public static void loadUserLoggingConfig() throws InvalidConfigurationException {
         File thermostatUserDir = new File(ConfigUtils.getThermostatUserHome());
         File loggingPropertiesFile = new File(thermostatUserDir, "logging.properties");
+        loadConfig(loggingPropertiesFile);
+    }
+
+    // for testing
+    static void loadConfig(File loggingPropertiesFile) throws InvalidConfigurationException {
         if (loggingPropertiesFile.isFile()) {
             readLoggingProperties(loggingPropertiesFile);
         }
@@ -129,11 +140,49 @@
 
     private static void readLoggingProperties(File loggingPropertiesFile)
             throws InvalidConfigurationException {
+        // Make sure root logger exists
+        ensureRootLogger();
         try (FileInputStream fis = new FileInputStream(loggingPropertiesFile)){
+            // Set basic logger configs. Note that this does NOT add handlers.
+            // It also resets() handlers. I.e. removes any existing handlers
+            // for the root logger.
             LogManager.getLogManager().readConfiguration(fis);
         } catch (SecurityException | IOException e) {
             throw new InvalidConfigurationException("Could not read logging.properties", e);
         }
+        try (FileInputStream fis = new FileInputStream(loggingPropertiesFile)) {
+            // Finally add handlers as specified in the property file, with
+            // ConsoleHandler and level INFO as default
+            configureLogging(getDefaultProps(), fis);
+        } catch (SecurityException | IOException e) {
+            throw new InvalidConfigurationException("Could not read logging.properties", e);
+        }
     }
 
+    private static void configureLogging(Properties defaultProps, FileInputStream fis) throws IOException {
+        Properties props = new Properties(defaultProps);
+        props.load(fis);
+        String handlers = props.getProperty(HANDLER_PROP);
+        for (String clazzName: handlers.split(",")) {
+            clazzName = clazzName.trim();
+            try {
+                // JVM provided class. Using system class loader is safe.
+                @SuppressWarnings("rawtypes")
+                Class clazz = ClassLoader.getSystemClassLoader().loadClass(clazzName);
+                Handler handler = (Handler)clazz.newInstance();
+                root.addHandler(handler);
+            } catch (Exception e) {
+                System.err.print("Could not load log-handler '" + clazzName + "'");
+                e.printStackTrace();
+            }
+        }
+    }
+
+    private static Properties getDefaultProps() {
+        Properties defaultProps = new Properties();
+        defaultProps.put(HANDLER_PROP, DEFAULT_LOG_HANDLER);
+        defaultProps.put(LOG_LEVEL_PROP, DEFAULT_LOG_LEVEL);
+        return defaultProps;
+    }
+
 }
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/common/core/src/test/java/com/redhat/thermostat/common/utils/LoggingUtilsTest.java	Thu Nov 29 18:11:52 2012 +0100
@@ -0,0 +1,127 @@
+/*
+ * Copyright 2012 Red Hat, Inc.
+ *
+ * This file is part of Thermostat.
+ *
+ * Thermostat is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published
+ * by the Free Software Foundation; either version 2, or (at your
+ * option) any later version.
+ *
+ * Thermostat is distributed in the hope that it will be useful, but
+ * WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+ * General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with Thermostat; see the file COPYING.  If not see
+ * <http://www.gnu.org/licenses/>.
+ *
+ * Linking this code with other modules is making a combined work
+ * based on this code.  Thus, the terms and conditions of the GNU
+ * General Public License cover the whole combination.
+ *
+ * As a special exception, the copyright holders of this code give
+ * you permission to link this code with independent modules to
+ * produce an executable, regardless of the license terms of these
+ * independent modules, and to copy and distribute the resulting
+ * executable under terms of your choice, provided that you also
+ * meet, for each linked independent module, the terms and conditions
+ * of the license of that module.  An independent module is a module
+ * which is not derived from or based on this code.  If you modify
+ * this code, you may extend this exception to your version of the
+ * library, but you are not obligated to do so.  If you do not wish
+ * to do so, delete this exception statement from your version.
+ */
+
+package com.redhat.thermostat.common.utils;
+
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.assertEquals;
+
+import java.io.File;
+import java.util.Enumeration;
+import java.util.logging.ConsoleHandler;
+import java.util.logging.FileHandler;
+import java.util.logging.Handler;
+import java.util.logging.Level;
+import java.util.logging.LogManager;
+import java.util.logging.Logger;
+import java.util.logging.SimpleFormatter;
+
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Test;
+
+public class LoggingUtilsTest {
+    
+    private static final File GLOBAL_CONFIG = new File(LoggingUtilsTest.class.getResource("/globalLogging.properties").getFile());
+    private static final File USER_CONFIG = new File(LoggingUtilsTest.class.getResource("/userLogging.properties").getFile());
+
+    private LogManager logManager;
+    private Logger mongodbLogger;
+    
+    @Before
+    public void setUp() {
+        // this is intentionally using Logger (not LoggingUtils)
+        mongodbLogger = Logger.getLogger("com.mongodb");
+        logManager = LogManager.getLogManager();
+    }
+    
+    @After
+    public void tearDown() {
+        LoggingUtils.root = null;
+        mongodbLogger = null;
+    }
+    
+    @Test
+    public void testGlobalLoggingHandlersAreCreated() throws Exception {
+        LoggingUtils.loadConfig(GLOBAL_CONFIG);
+        verifyContainsRootLogger(logManager.getLoggerNames());
+        Logger rootLogger = logManager.getLogger(LoggingUtils.ROOTNAME);
+        FileHandler handler = (FileHandler)getLogHandler(rootLogger, FileHandler.class);
+        assertNotNull(handler);
+        assertEquals(SimpleFormatter.class.getName(), handler.getFormatter().getClass().getName());
+        assertEquals(Level.WARNING.getName(), rootLogger.getLevel().getName());
+        assertEquals(Level.OFF.getName(), mongodbLogger.getLevel().getName());
+        
+    }
+    
+    @Test
+    public void testUserLoggingConfigOverridesGlobal() throws Exception {
+        LoggingUtils.loadConfig(GLOBAL_CONFIG);
+        LoggingUtils.loadConfig(USER_CONFIG);
+        verifyContainsRootLogger(logManager.getLoggerNames());
+        Logger rootLogger = logManager.getLogger(LoggingUtils.ROOTNAME);
+        // global config has FileHandler, user config ConsoleHandler
+        ConsoleHandler handler = (ConsoleHandler)getLogHandler(rootLogger, ConsoleHandler.class);
+        assertNotNull(handler);
+        assertEquals(Level.FINEST.getName(), rootLogger.getLevel().getName());
+        assertEquals(Level.INFO.getName(), mongodbLogger.getLevel().getName());
+    }
+
+    @SuppressWarnings("rawtypes") 
+    private Handler getLogHandler(Logger logger, Class clazz) {
+        Handler[] handlers = logger.getHandlers();
+        assertEquals(1, handlers.length);
+        for (Handler handler: logger.getHandlers()) {
+            if (handler.getClass().getName().equals(clazz.getName())) {
+                return handler;
+            }
+        }
+        return null;
+    }
+
+    private void verifyContainsRootLogger(Enumeration<String> loggerNames) {
+        boolean found = false;
+        while (loggerNames.hasMoreElements()) {
+            String logger = loggerNames.nextElement();
+            if (logger.equals(LoggingUtils.ROOTNAME)) {
+                found = true;
+                break;
+            }
+        }
+        assertTrue(found);
+    }
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/common/core/src/test/resources/globalLogging.properties	Thu Nov 29 18:11:52 2012 +0100
@@ -0,0 +1,30 @@
+com.redhat.thermostat.handlers=java.util.logging.FileHandler
+# To add a ConsoleHandler AND FileHandler, use the following line instead.
+#com.redhat.thermostat.handlers=java.util.logging.FileHandler, java.util.logging.ConsoleHandler
+
+# You may use standard configs for log handlers.
+# See: http://docs.oracle.com/javase/7/docs/api/java/util/logging/FileHandler.html
+# For example:
+#java.util.logging.FileHandler.pattern = %h/.thermostat/logs/thermostat.log
+#java.util.logging.FileHandler.limit = 50000
+#java.util.logging.FileHandler.append = true
+#java.util.logging.FileHandler.count = 1
+java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter
+
+###################################################################
+# Thermostat log level config. Default log level is INFO. 
+###################################################################
+# Possible levels are in descending order:
+#com.redhat.thermostat.level=SEVERE
+com.redhat.thermostat.level=WARNING
+#com.redhat.thermostat.level=INFO
+#com.redhat.thermostat.level=CONFIG
+#com.redhat.thermostat.level=FINE
+#com.redhat.thermostat.level=FINER
+#com.redhat.thermostat.level=FINEST
+#com.redhat.thermostat.level=OFF
+
+###################################################################
+# Other log levels
+###################################################################
+com.mongodb.level=OFF
\ No newline at end of file
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/common/core/src/test/resources/userLogging.properties	Thu Nov 29 18:11:52 2012 +0100
@@ -0,0 +1,30 @@
+com.redhat.thermostat.handlers=java.util.logging.ConsoleHandler
+# To add a ConsoleHandler AND FileHandler, use the following line instead.
+#com.redhat.thermostat.handlers=java.util.logging.FileHandler, java.util.logging.ConsoleHandler
+
+# You may use standard configs for log handlers.
+# See: http://docs.oracle.com/javase/7/docs/api/java/util/logging/FileHandler.html
+# For example:
+#java.util.logging.FileHandler.pattern = %h/.thermostat/logs/thermostat.log
+#java.util.logging.FileHandler.limit = 50000
+#java.util.logging.FileHandler.append = true
+#java.util.logging.FileHandler.count = 1
+#java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter
+
+###################################################################
+# Thermostat log level config. Default log level is INFO. 
+###################################################################
+# Possible levels are in descending order:
+#com.redhat.thermostat.level=SEVERE
+#com.redhat.thermostat.level=WARNING
+#com.redhat.thermostat.level=INFO
+#com.redhat.thermostat.level=CONFIG
+#com.redhat.thermostat.level=FINE
+#com.redhat.thermostat.level=FINER
+com.redhat.thermostat.level=FINEST
+#com.redhat.thermostat.level=OFF
+
+###################################################################
+# Other log levels
+###################################################################
+com.mongodb.level=INFO
\ No newline at end of file
--- a/distribution/config/logging.properties	Thu Nov 29 17:06:15 2012 -0500
+++ b/distribution/config/logging.properties	Thu Nov 29 18:11:52 2012 +0100
@@ -32,6 +32,37 @@
 # library, but you are not obligated to do so.  If you do not wish
 # to do so, delete this exception statement from your version.
 
-handlers=java.util.logging.ConsoleHandler
-com.redhat.thermostat.level=INFO
+###################################################################
+# Handler config (thermostat installs a ConsoleHandler by default).
+###################################################################
+# If you want a FileHandler instead use:
+#com.redhat.thermostat.handlers=java.util.logging.FileHandler
+# To add a ConsoleHandler AND FileHandler, use the following line instead.
+#com.redhat.thermostat.handlers=java.util.logging.FileHandler, java.util.logging.ConsoleHandler
+
+# You may use standard configs for log handlers.
+# See: http://docs.oracle.com/javase/7/docs/api/java/util/logging/FileHandler.html
+# For example:
+#java.util.logging.FileHandler.pattern = %h/.thermostat/logs/thermostat.log
+#java.util.logging.FileHandler.limit = 50000
+#java.util.logging.FileHandler.append = true
+#java.util.logging.FileHandler.count = 1
+#java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter
+
+###################################################################
+# Thermostat log level config. Default log level is INFO. 
+###################################################################
+# Possible levels are in descending order:
+#com.redhat.thermostat.level=SEVERE
+#com.redhat.thermostat.level=WARNING
+#com.redhat.thermostat.level=INFO
+#com.redhat.thermostat.level=CONFIG
+#com.redhat.thermostat.level=FINE
+#com.redhat.thermostat.level=FINER
+com.redhat.thermostat.level=FINEST
+#com.redhat.thermostat.level=OFF
+
+###################################################################
+# Other log levels
+###################################################################
 com.mongodb.level=OFF
--- a/unix-process-handler/src/main/java/com/redhat/thermostat/service/activator/Activator.java	Thu Nov 29 17:06:15 2012 -0500
+++ b/unix-process-handler/src/main/java/com/redhat/thermostat/service/activator/Activator.java	Thu Nov 29 18:11:52 2012 +0100
@@ -43,12 +43,13 @@
 import org.osgi.framework.BundleActivator;
 import org.osgi.framework.BundleContext;
 
+import com.redhat.thermostat.common.utils.LoggingUtils;
 import com.redhat.thermostat.service.process.UNIXProcessHandler;
 import com.redhat.thermostat.service.process.UnixProcessUtilities;
 
 public class Activator implements BundleActivator {
 
-    private static final Logger logger = Logger.getLogger(Activator.class.getSimpleName());
+    private static final Logger logger = LoggingUtils.getLogger(Activator.class);
     
     @Override
     public void start(BundleContext context) throws Exception {