Consolidate Logging

- Use sl4fj as a backend to org.libresonic.Logger
- Output the same logs to libresonic.log as the console
- Use spring-boot logging constructs
- Turn down logging to error for non-libresonic classes info for
  libresonic classes and liquibase (perhaps change this in the future,
  but might be helpful for folks migrating their databases).

Signed-off-by: Andrew DeMaria <lostonamountain@gmail.com>

libresonic-main/pom.xml

@@ -121,7 +121,7 @@
         <dependency>
             <groupId>commons-io</groupId>
             <artifactId>commons-io</artifactId>
-            <version>1.3.1</version>
+            <version>2.5</version>
         </dependency>
 
         <dependency>
@@ -387,6 +387,12 @@
             <artifactId>validation-api</artifactId>
             <version>1.1.0.Final</version>
         </dependency>
+
+        <dependency>
+            <groupId>org.slf4j</groupId>
+            <artifactId>slf4j-api</artifactId>
+            <version>1.7.24</version>
+        </dependency>
     </dependencies>
 
     <build>

libresonic-main/src/main/java/org/libresonic/player/Logger.java

@@ -19,40 +19,15 @@
  */
 package org.libresonic.player;
 
-import org.apache.commons.lang.exception.ExceptionUtils;
-import org.libresonic.player.domain.Version;
-import org.libresonic.player.service.ServiceLocator;
-import org.libresonic.player.service.SettingsService;
-import org.libresonic.player.service.VersionService;
-import org.libresonic.player.util.BoundedList;
-
-import java.io.File;
-import java.io.FileWriter;
-import java.io.IOException;
-import java.io.PrintWriter;
-import java.text.DateFormat;
-import java.text.SimpleDateFormat;
-import java.util.Collections;
-import java.util.Date;
-import java.util.List;
+import org.slf4j.LoggerFactory;
 
 /**
- * Logger implementation which logs to LIBRESONIC_HOME/libresonic.log.
- * <br/>
- * Note: Third party logging libraries (such as log4j and Commons logging) are intentionally not
- * used. These libraries causes a lot of headache when deploying to some application servers
- * (for instance Jetty and JBoss).
- *
- * @author Sindre Mehus
- * @version $Revision: 1.1 $ $Date: 2005/05/09 19:58:26 $
+ * Proxy to Slf4j Logger.
  */
+@Deprecated
 public class Logger {
 
-    private String category;
-
-    private static List<Entry> entries = Collections.synchronizedList(new BoundedList<Entry>(50));
-    private static PrintWriter writer;
-    private static Boolean debugEnabled;
+    private final org.slf4j.Logger internalLogger;
 
     /**
      * Creates a logger for the given class.
@@ -72,29 +47,17 @@ public class Logger {
         return new Logger(name);
     }
 
-    /**
-     * Returns the last few log entries.
-     * @return The last few log entries.
-     */
-    public static Entry[] getLatestLogEntries() {
-        return entries.toArray(new Entry[entries.size()]);
-    }
 
     private Logger(String name) {
-        int lastDot = name.lastIndexOf('.');
-        if (lastDot == -1) {
-            category = name;
-        } else {
-            category = name.substring(lastDot + 1);
-        }
+        internalLogger = LoggerFactory.getLogger(name);
     }
 
     /**
      * Logs a debug message.
      * @param message The log message.
      */
-    public void debug(Object message) {
-        debug(message, null);
+    public void debug(String message) {
+        internalLogger.debug(message);
     }
 
     /**
@@ -102,30 +65,16 @@ public class Logger {
      * @param message The message.
      * @param error The optional exception.
      */
-    public void debug(Object message, Throwable error) {
-        if (isDebugEnabled()) {
-            add(Level.DEBUG, message, error);
-        }
-    }
-
-    private static boolean isDebugEnabled() {
-        if (debugEnabled == null) {
-            VersionService versionService = ServiceLocator.getVersionService();
-            if (versionService == null) {
-                return true;  // versionService not yet available.
-            }
-            Version localVersion = versionService.getLocalVersion();
-            debugEnabled = localVersion == null || localVersion.isPreview();
-        }
-        return debugEnabled;
+    public void debug(String message, Throwable error) {
+        internalLogger.debug(message, error);
     }
 
     /**
      * Logs an info message.
      * @param message The message.
      */
-    public void info(Object message) {
-        info(message, null);
+    public void info(String message) {
+        internalLogger.info(message);
     }
 
     /**
@@ -133,16 +82,16 @@ public class Logger {
      * @param message The message.
      * @param error The optional exception.
      */
-    public void info(Object message, Throwable error) {
-        add(Level.INFO, message, error);
+    public void info(String message, Throwable error) {
+        internalLogger.info(message, error);
     }
 
     /**
      * Logs a warning message.
      * @param message The message.
      */
-    public void warn(Object message) {
-        warn(message, null);
+    public void warn(String message) {
+        internalLogger.warn(message);
     }
 
     /**
@@ -150,16 +99,16 @@ public class Logger {
      * @param message The message.
      * @param error The optional exception.
      */
-    public void warn(Object message, Throwable error) {
-        add(Level.WARN, message, error);
+    public void warn(String message, Throwable error) {
+        internalLogger.warn(message, error);
     }
 
     /**
      * Logs an error message.
      * @param message The message.
      */
-    public void error(Object message) {
-        error(message, null);
+    public void error(String message) {
+        internalLogger.error(message);
     }
 
     /**
@@ -167,89 +116,8 @@ public class Logger {
      * @param message The message.
      * @param error The optional exception.
      */
-    public void error(Object message, Throwable error) {
-        add(Level.ERROR, message, error);
-    }
-
-    private void add(Level level, Object message, Throwable error) {
-        Entry entry = new Entry(category, level, message, error);
-        try {
-            getPrintWriter().println(entry);
-        } catch (IOException x) {
-            System.err.println("Failed to write to libresonic.log. " + x);
-        }
-        entries.add(entry);
-    }
-
-    private static synchronized PrintWriter getPrintWriter() throws IOException {
-        if (writer == null) {
-            writer = new PrintWriter(new FileWriter(getLogFile(), false), true);
-        }
-        return writer;
-    }
-
-    public static File getLogFile() {
-        File libresonicHome = SettingsService.getLibresonicHome();
-        return new File(libresonicHome, "libresonic.log");
+    public void error(String message, Throwable error) {
+        internalLogger.error(message, error);
     }
 
-    /**
-    * Log level.
-    */
-    public enum Level {
-        DEBUG, INFO, WARN, ERROR
-    }
-
-    /**
-     * Log entry.
-     */
-    public static class Entry {
-        private String category;
-        private Date date;
-        private Level level;
-        private Object message;
-        private Throwable error;
-        private static final DateFormat DATE_FORMAT = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss,SSS");
-
-        public Entry(String category, Level level, Object message, Throwable error) {
-            this.date = new Date();
-            this.category = category;
-            this.level = level;
-            this.message = message;
-            this.error = error;
-        }
-
-        public String getCategory() {
-            return category;
-        }
-
-        public Date getDate() {
-            return date;
-        }
-
-        public Level getLevel() {
-            return level;
-        }
-
-        public Object getMessage() {
-            return message;
-        }
-
-        public Throwable getError() {
-            return error;
-        }
-
-        public String toString() {
-            StringBuilder builder = new StringBuilder();
-            builder.append('[').append(DATE_FORMAT.format(date)).append("] ");
-            builder.append(level).append(' ');
-            builder.append(category).append(" - ");
-            builder.append(message);
-
-            if (error != null) {
-                builder.append('\n').append(ExceptionUtils.getFullStackTrace(error));
-            }
-            return builder.toString();
-        }
-    }
 }

libresonic-main/src/main/java/org/libresonic/player/controller/HelpController.java

@@ -19,6 +19,7 @@
  */
 package org.libresonic.player.controller;
 
+import org.apache.commons.io.input.ReversedLinesFileReader;
 import org.libresonic.player.Logger;
 import org.libresonic.player.service.SecurityService;
 import org.libresonic.player.service.SettingsService;
@@ -32,7 +33,11 @@ import org.springframework.web.servlet.ModelAndView;
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
 
+import java.io.File;
+import java.nio.charset.Charset;
+import java.util.ArrayList;
 import java.util.HashMap;
+import java.util.List;
 import java.util.Map;
 
 /**
@@ -44,6 +49,10 @@ import java.util.Map;
 @RequestMapping("/help")
 public class HelpController {
 
+    private static final Logger logger = Logger.getLogger(HelpController.class);
+
+    private static final int LOG_LINES_TO_SHOW = 50;
+
     @Autowired
     private VersionService versionService;
     @Autowired
@@ -78,12 +87,28 @@ public class HelpController {
         map.put("serverInfo", serverInfo);
         map.put("usedMemory", totalMemory - freeMemory);
         map.put("totalMemory", totalMemory);
-        map.put("logEntries", Logger.getLatestLogEntries());
-        map.put("logFile", Logger.getLogFile());
+        File logFile = SettingsService.getLogFile();
+        List<String> latestLogEntries = getLatestLogEntries(logFile);
+        map.put("logEntries", latestLogEntries);
+        map.put("logFile", logFile);
 
         return new ModelAndView("help","model",map);
     }
 
+    private static List<String> getLatestLogEntries(File logFile) {
+        try {
+            List<String> lines = new ArrayList<>(LOG_LINES_TO_SHOW);
+            ReversedLinesFileReader reader = new ReversedLinesFileReader(logFile, Charset.defaultCharset());
+            String current;
+            while((current = reader.readLine()) != null && lines.size() < LOG_LINES_TO_SHOW) {
+                lines.add(0, current);
+            }
+            return lines;
+        } catch (Exception e) {
+            logger.warn("Could not open log file " + logFile, e);
+            return null;
+        }
+    }
 
 
 }

libresonic-main/src/main/java/org/libresonic/player/io/TranscodeInputStream.java

@@ -59,7 +59,7 @@ public class TranscodeInputStream extends InputStream {
         for (String s : processBuilder.command()) {
             buf.append('[').append(s).append("] ");
         }
-        LOG.info(buf);
+        LOG.info(buf.toString());
 
         process = processBuilder.start();
         processOutputStream = process.getOutputStream();

libresonic-main/src/main/java/org/libresonic/player/service/SettingsService.java

@@ -246,6 +246,11 @@ public class SettingsService {
         return home;
     }
 
+    public static File getLogFile() {
+        File libresonicHome = SettingsService.getLibresonicHome();
+        return new File(libresonicHome, "libresonic.log");
+    }
+
 
     /**
      * Register in service locator so that non-Spring objects can access me.

libresonic-main/src/main/java/org/libresonic/player/spring/LoggingFileOverrideListener.java

@@ -0,0 +1,30 @@
+package org.libresonic.player.spring;
+
+import org.springframework.boot.context.event.ApplicationEnvironmentPreparedEvent;
+import org.springframework.boot.logging.LogFile;
+import org.springframework.boot.logging.LoggingApplicationListener;
+import org.springframework.context.ApplicationListener;
+import org.springframework.core.Ordered;
+import org.springframework.core.env.MapPropertySource;
+import org.springframework.core.env.PropertySource;
+
+import java.util.Collections;
+
+import static org.libresonic.player.service.SettingsService.getLogFile;
+
+
+public class LoggingFileOverrideListener implements ApplicationListener<ApplicationEnvironmentPreparedEvent>, Ordered {
+
+    @Override
+    public void onApplicationEvent(ApplicationEnvironmentPreparedEvent event) {
+        PropertySource ps = new MapPropertySource("LogFileLocationPS",
+                Collections.singletonMap(LogFile.FILE_PROPERTY, getLogFile().getAbsolutePath()));
+        event.getEnvironment().getPropertySources().addLast(ps);
+    }
+
+    @Override
+    public int getOrder() {
+        return LoggingApplicationListener.DEFAULT_ORDER - 1;
+    }
+
+}

libresonic-main/src/main/resources/META-INF/spring.factories

@@ -0,0 +1 @@
+org.springframework.context.ApplicationListener=org.libresonic.player.spring.LoggingFileOverrideListener

libresonic-main/src/main/resources/application.properties

@@ -1,4 +1,8 @@
 spring.mvc.view.prefix: /WEB-INF/jsp/
 spring.mvc.view.suffix: .jsp
 server.error.includeStacktrace: ALWAYS
-logging.level.org.springframework.web=INFO
+logging.level.root=WARN
+logging.level.org.libresonic=INFO
+logging.level.liquibase=INFO
+logging.pattern.console=%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(%5p){green} %clr(---){faint} %clr(%-40.40logger{32}){blue} %clr(:){faint} %m%n%wEx
+logging.pattern.file=%d{yyyy-MM-dd HH:mm:ss.SSS} %5p --- %-40.40logger{32} : %m%n%wEx

libresonic-main/src/main/resources/banner.txt

@@ -1,8 +1,8 @@
-${AnsiColor.BRIGHT_BLUE}  _      _ _              ${AnsiColor.BRIGHT_BLACK}                 _       ______
-${AnsiColor.BRIGHT_BLUE} | |    (_) |             ${AnsiColor.BRIGHT_BLACK}                (_)      \ \ \ \
-${AnsiColor.BRIGHT_BLUE} | |     _| |__  _ __ ___ ${AnsiColor.BRIGHT_BLACK} ___  ___  _ __  _  ___   | | | |
-${AnsiColor.BRIGHT_BLUE} | |    | | '_ \| '__/ _ \${AnsiColor.BRIGHT_BLACK}/ __|/ _ \| '_ \| |/ __|  | | | |
-${AnsiColor.BRIGHT_BLUE} | |____| | |_) | | |  __/${AnsiColor.BRIGHT_BLACK}\__ \ (_) | | | | | (__   | | | |
-${AnsiColor.BRIGHT_BLUE} |______|_|_.__/|_|  \___|${AnsiColor.BRIGHT_BLACK}|___/\___/|_| |_|_|\___|  | | | |
-${AnsiColor.BRIGHT_BLUE}                          ${AnsiColor.BRIGHT_BLACK}                         /_/_/_/
-${AnsiColor.BRIGHT_BLUE}                          ${AnsiColor.BRIGHT_BLACK}      ${application.version}
+${AnsiColor.BLUE}  _      _ _              ${AnsiColor.BRIGHT_BLACK}                 _       ______
+${AnsiColor.BLUE} | |    (_) |             ${AnsiColor.BRIGHT_BLACK}                (_)      \ \ \ \
+${AnsiColor.BLUE} | |     _| |__  _ __ ___ ${AnsiColor.BRIGHT_BLACK} ___  ___  _ __  _  ___   | | | |
+${AnsiColor.BLUE} | |    | | '_ \| '__/ _ \${AnsiColor.BRIGHT_BLACK}/ __|/ _ \| '_ \| |/ __|  | | | |
+${AnsiColor.BLUE} | |____| | |_) | | |  __/${AnsiColor.BRIGHT_BLACK}\__ \ (_) | | | | | (__   | | | |
+${AnsiColor.BLUE} |______|_|_.__/|_|  \___|${AnsiColor.BRIGHT_BLACK}|___/\___/|_| |_|_|\___|  | | | |
+${AnsiColor.BLUE}                          ${AnsiColor.BRIGHT_BLACK}                         /_/_/_/
+${AnsiColor.BLUE}                          ${AnsiColor.BRIGHT_BLACK}      ${application.version}

libresonic-main/src/main/webapp/WEB-INF/jsp/help.jsp

@@ -56,8 +56,7 @@
 <table cellpadding="2" class="log indent">
     <c:forEach items="${model.logEntries}" var="entry">
         <tr>
-            <td>[<fmt:formatDate value="${entry.date}" dateStyle="short" timeStyle="long" type="both"/>]</td>
-            <td>${entry.level}</td><td>${entry.category}</td><td>${fn:escapeXml(entry.message)}</td>
+            <td>${fn:escapeXml(entry)}</td>
         </tr>
     </c:forEach>
 </table>