JAL-3949 Complete new abstracted logging framework in jalview.log. Updated log calls...
[jalview.git] / src / jalview / bin / Cache.java
index 250f378..1a4f341 100755 (executable)
@@ -47,18 +47,11 @@ import java.util.regex.Pattern;
 import javax.swing.LookAndFeel;
 import javax.swing.UIManager;
 
-import org.apache.logging.log4j.Level;
-import org.apache.logging.log4j.LogManager;
-import org.apache.logging.log4j.Logger;
-import org.apache.logging.log4j.core.config.Configurator;
-import org.apache.logging.log4j.core.config.builder.api.AppenderComponentBuilder;
-import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder;
-import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory;
-import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration;
-
 import jalview.datamodel.PDBEntry;
 import jalview.gui.Preferences;
 import jalview.gui.UserDefinedColours;
+import jalview.log.JLogger;
+import jalview.log.JLoggerLog4j;
 import jalview.schemes.ColourSchemeLoader;
 import jalview.schemes.ColourSchemes;
 import jalview.schemes.UserColourScheme;
@@ -280,7 +273,10 @@ public class Cache
   /**
    * Initialises the Jalview Application Log
    */
-  public static Logger log;
+
+  public final static String JALVIEW_LOGGER_NAME = "JalviewLogger";
+
+  public static JLoggerLog4j log;
 
   // save the proxy properties set at startup
   public final static String[] startupProxyProperties = {
@@ -325,45 +321,58 @@ public class Cache
 
   private final static String JS_PROPERTY_PREFIX = "jalview_";
 
-  public static void initLogger()
+  public final static String LOGGING_TEST_MESSAGE = "Logging to STDERR";
+
+  public static JLogger.LogLevel getCachedLogLevel()
+  {
+    return getCachedLogLevel(JALVIEWLOGLEVEL);
+  }
+
+  public static JLogger.LogLevel getCachedLogLevel(String key)
+  {
+    return JLogger.toLevel(Cache.getDefault(key, "INFO"));
+  }
+
+  public static boolean initLogger()
   {
     if (log != null)
     {
-      return;
+      return true;
     }
     try
     {
-      // configure the root logger to stderr
-      ConfigurationBuilder<BuiltConfiguration> builder = ConfigurationBuilderFactory
-              .newConfigurationBuilder();
-      AppenderComponentBuilder consoleApp = builder.newAppender("stderr",
-              "Console");
-      builder.add(consoleApp);
-      Configurator.initialize(builder.build());
+      JLogger.LogLevel cachedLevel = getCachedLogLevel();
+      if (!Platform.isJS())
+      {
+        Log4j.init(cachedLevel);
+      }
       // log output
-      Logger laxis = LogManager.getLogger("org.apache.axis");
-      log = LogManager.getLogger("jalview.bin.Jalview");
-
-      Log4j.setLevel(laxis, Level.toLevel(
-              Cache.getDefault("logs.Axis.Level", Level.INFO.toString())));
-      // lcastor = Logger.getLogger("org.exolab.castor.xml.Marshaller");
-      // lcastor.setLevel(Level.toLevel(Cache.getDefault("logs.Castor.Level",
-      // Level.INFO.toString())));
-      // we shouldn't need to do this
-      Log4j.setRootLevel(Level.INFO);
-
-      Log4j.setLevel(log, Level.toLevel(Cache
-              .getDefault("logs.Jalview.level", Level.INFO.toString())));
-      // laxis.addAppender(ap);
-      // lcastor.addAppender(ap);
-      // jalview.bin.Cache.log.addAppender(ap);
+      // is laxis used? Does getLogger do anything without a Logger object?
+      // Logger laxis = Log4j.getLogger("org.apache.axis", myLevel);
+      JLoggerLog4j.getLogger("org.apache.axis", cachedLevel);
+
+      // The main application logger
+      log = JLoggerLog4j.getLogger(JALVIEW_LOGGER_NAME, cachedLevel);
+    } catch (NoClassDefFoundError e)
+    {
+      System.err.println("Could not initialise the logger framework");
+      e.printStackTrace();
+    }
+
+    // Test message
+    if (log != null)
+    {
+      // Logging test message should got through the logger object
+      if (log.loggerExists())
+        log.debug(LOGGING_TEST_MESSAGE);
       // Tell the user that debug is enabled
-      log.debug(ChannelProperties.getProperty("app_name")
+      Cache.debug(ChannelProperties.getProperty("app_name")
               + " Debugging Output Follows.");
-    } catch (Exception ex)
+      return true;
+    }
+    else
     {
-      System.err.println("Problems initializing the log4j system\n");
-      ex.printStackTrace(System.err);
+      return false;
     }
   }
 
@@ -509,27 +518,27 @@ public class Cache
     SiftsSettings
             .setMapWithSifts(Cache.getDefault("MAP_WITH_SIFTS", false));
 
-    SiftsSettings.setSiftDownloadDirectory(jalview.bin.Cache
+    SiftsSettings.setSiftDownloadDirectory(Cache
             .getDefault("sifts_download_dir", DEFAULT_SIFTS_DOWNLOAD_DIR));
 
     SiftsSettings.setFailSafePIDThreshold(
-            jalview.bin.Cache.getDefault("sifts_fail_safe_pid_threshold",
+            Cache.getDefault("sifts_fail_safe_pid_threshold",
                     DEFAULT_FAIL_SAFE_PID_THRESHOLD));
 
     SiftsSettings.setCacheThresholdInDays(
-            jalview.bin.Cache.getDefault("sifts_cache_threshold_in_days",
+            Cache.getDefault("sifts_cache_threshold_in_days",
                     DEFAULT_CACHE_THRESHOLD_IN_DAYS));
 
     IdOrgSettings.setUrl(getDefault("ID_ORG_HOSTURL",
             "https://www.jalview.org/services/identifiers"));
     IdOrgSettings.setDownloadLocation(ID_ORG_FILE);
 
-    StructureImportSettings.setDefaultStructureFileFormat(jalview.bin.Cache
-            .getDefault("PDB_DOWNLOAD_FORMAT", PDB_DOWNLOAD_FORMAT));
+    StructureImportSettings.setDefaultStructureFileFormat(
+            Cache.getDefault("PDB_DOWNLOAD_FORMAT", PDB_DOWNLOAD_FORMAT));
     StructureImportSettings
             .setDefaultPDBFileParser(DEFAULT_PDB_FILE_PARSER);
     // StructureImportSettings
-    // .setDefaultPDBFileParser(jalview.bin.Cache.getDefault(
+    // .setDefaultPDBFileParser(Cache.getDefault(
     // "DEFAULT_PDB_FILE_PARSER", DEFAULT_PDB_FILE_PARSER));
 
     String jnlpVersion = System.getProperty("jalview.version");
@@ -850,14 +859,11 @@ public class Cache
         if (jalview.jbgui.GDesktop.class.getClassLoader()
                 .loadClass("uk.ac.vamsas.client.VorbaId") != null)
         {
-          log.debug(
-                  "Found Vamsas Classes (uk.ac..vamsas.client.VorbaId can be loaded)");
+          debug("Found Vamsas Classes (uk.ac..vamsas.client.VorbaId can be loaded)");
           vamsasJarsArePresent = 1;
-          Logger lvclient = LogManager.getLogger("uk.ac.vamsas");
-          Log4j.setLevel(lvclient, Level.toLevel(Cache
-                  .getDefault("logs.Vamsas.Level", Level.INFO.toString())));
-
-          Log4j.addAppender(lvclient, log, "JalviewLogger");
+          JLoggerLog4j lvclient = JLoggerLog4j.getLogger("uk.ac.vamsas",
+                  getCachedLogLevel("logs.Vamsas.Level"));
+          JLoggerLog4j.addAppender(lvclient, log, JALVIEW_LOGGER_NAME);
           // Tell the user that debug is enabled
           lvclient.debug(ChannelProperties.getProperty("app_name")
                   + " Vamsas Client Debugging Output Follows.");
@@ -865,7 +871,7 @@ public class Cache
       } catch (Exception e)
       {
         vamsasJarsArePresent = 0;
-        log.debug("Vamsas Classes are not present");
+        debug("Vamsas Classes are not present");
       }
     }
     return (vamsasJarsArePresent > 0);
@@ -890,14 +896,11 @@ public class Cache
         if (Cache.class.getClassLoader()
                 .loadClass("groovy.lang.GroovyObject") != null)
         {
-          log.debug(
-                  "Found Groovy (groovy.lang.GroovyObject can be loaded)");
+          debug("Found Groovy (groovy.lang.GroovyObject can be loaded)");
           groovyJarsArePresent = 1;
-          Logger lgclient = LogManager.getLogger("groovy");
-          Log4j.setLevel(lgclient, Level.toLevel(Cache
-                  .getDefault("logs.Groovy.Level", Level.INFO.toString())));
-
-          Log4j.addAppender(lgclient, log, "JalviewLogger");
+          JLoggerLog4j lgclient = JLoggerLog4j.getLogger("groovy",
+                  getCachedLogLevel("logs.Groovy.Level"));
+          JLoggerLog4j.addAppender(lgclient, log, JALVIEW_LOGGER_NAME);
           // Tell the user that debug is enabled
           lgclient.debug(ChannelProperties.getProperty("app_name")
                   + " Groovy Client Debugging Output Follows.");
@@ -905,11 +908,11 @@ public class Cache
       } catch (Error e)
       {
         groovyJarsArePresent = 0;
-        log.debug("Groovy Classes are not present", e);
+        debug("Groovy Classes are not present", e);
       } catch (Exception e)
       {
         groovyJarsArePresent = 0;
-        log.debug("Groovy Classes are not present");
+        debug("Groovy Classes are not present");
       }
     }
     return (groovyJarsArePresent > 0);
@@ -943,8 +946,7 @@ public class Cache
                   .loadClass("com.boxysystems.jgoogleanalytics.FocusPoint");
         } catch (Exception e)
         {
-          log.debug(
-                  "com.boxysystems.jgoogleanalytics package is not present - tracking not enabled.");
+          debug("com.boxysystems.jgoogleanalytics package is not present - tracking not enabled.");
           tracker = null;
           jgoogleanalyticstracker = null;
           trackerfocus = null;
@@ -963,9 +965,8 @@ public class Cache
                 { String.class, String.class, String.class })
                 .newInstance(new Object[]
                 { ChannelProperties.getProperty("app_name") + " Desktop",
-                    (vrs = jalview.bin.Cache.getProperty("VERSION") + "_"
-                            + jalview.bin.Cache.getDefault("BUILD_DATE",
-                                    "unknown")),
+                    (vrs = Cache.getProperty("VERSION") + "_"
+                            + Cache.getDefault("BUILD_DATE", "unknown")),
                     "UA-9060947-1" });
         jgoogleanalyticstracker
                 .getMethod("trackAsynchronously", new Class[]
@@ -986,57 +987,24 @@ public class Cache
       }
       if (re != null || ex != null || err != null)
       {
-        if (log != null)
+        if (re != null)
         {
-          if (re != null)
-          {
-            log.debug("Caught runtime exception in googletracker init:",
-                    re);
-          }
-          if (ex != null)
-          {
-            log.warn(
-                    "Failed to initialise GoogleTracker for Jalview Desktop with version "
-                            + vrs,
-                    ex);
-          }
-          if (err != null)
-          {
-            log.error(
-                    "Whilst initing GoogleTracker for Jalview Desktop version "
-                            + vrs,
-                    err);
-          }
+          debug("Caught runtime exception in googletracker init:", re);
         }
-        else
+        if (ex != null)
         {
-          if (re != null)
-          {
-            System.err.println(
-                    "Debug: Caught runtime exception in googletracker init:"
-                            + vrs);
-            re.printStackTrace();
-          }
-          if (ex != null)
-          {
-            System.err.println(
-                    "Warning:  Failed to initialise GoogleTracker for Jalview Desktop with version "
-                            + vrs);
-            ex.printStackTrace();
-          }
-
-          if (err != null)
-          {
-            System.err.println(
-                    "ERROR: Whilst initing GoogleTracker for Jalview Desktop version "
-                            + vrs);
-            err.printStackTrace();
-          }
+          warn("Failed to initialise GoogleTracker for Jalview Desktop with version "
+                  + vrs, ex);
+        }
+        if (err != null)
+        {
+          error("Whilst initing GoogleTracker for Jalview Desktop version "
+                  + vrs, err);
         }
       }
       else
       {
-        log.debug("Successfully initialised tracker.");
+        debug("Successfully initialised tracker.");
       }
     }
   }
@@ -1058,8 +1026,7 @@ public class Cache
     Color col = ColorUtils.parseColourString(colprop);
     if (col == null)
     {
-      log.warn("Couldn't parse '" + colprop + "' as a colour for "
-              + property);
+      warn("Couldn't parse '" + colprop + "' as a colour for " + property);
     }
     return (col == null) ? defcolour : col;
   }
@@ -1240,14 +1207,14 @@ public class Cache
     StringBuilder sb = new StringBuilder();
     sb.append(ChannelProperties.getProperty("app_name"))
             .append(" Version: ");
-    sb.append(jalview.bin.Cache.getDefault("VERSION", "TEST"));
+    sb.append(Cache.getDefault("VERSION", "TEST"));
     sb.append("\n");
     sb.append(ChannelProperties.getProperty("app_name"))
             .append(" Installation: ");
-    sb.append(jalview.bin.Cache.getDefault("INSTALLATION", "unknown"));
+    sb.append(Cache.getDefault("INSTALLATION", "unknown"));
     sb.append("\n");
     sb.append("Build Date: ");
-    sb.append(jalview.bin.Cache.getDefault("BUILD_DATE", "unknown"));
+    sb.append(Cache.getDefault("BUILD_DATE", "unknown"));
     sb.append("\n");
     sb.append("Java version: ");
     sb.append(System.getProperty("java.version"));
@@ -1275,7 +1242,7 @@ public class Cache
     // Not displayed in release version ( determined by possible version number
     // regex 9[9.]*9[.-_a9]* )
     if (Pattern.matches("^\\d[\\d\\.]*\\d[\\.\\-\\w]*$",
-            jalview.bin.Cache.getDefault("VERSION", "TEST")))
+            Cache.getDefault("VERSION", "TEST")))
     {
       appendIfNotNull(sb, "Getdown appdir: ",
               System.getProperty("getdownappdir"), "\n", null);
@@ -1295,7 +1262,7 @@ public class Cache
   {
     // consider returning more human friendly info
     // eg 'built from Source' or update channel
-    return jalview.bin.Cache.getDefault("INSTALLATION", "unknown");
+    return Cache.getDefault("INSTALLATION", "unknown");
   }
 
   public static String getStackTraceString(Throwable t)
@@ -1365,7 +1332,7 @@ public class Cache
     case Cache.PROXYTYPE_NONE:
       if (!previousProxyType.equals(proxyType))
       {
-        Cache.log.info("Setting no proxy settings");
+        Cache.info("Setting no proxy settings");
         Cache.setProxyProperties(null, null, null, null, null, null, null,
                 null, null);
       }
@@ -1373,7 +1340,7 @@ public class Cache
     case Cache.PROXYTYPE_CUSTOM:
       // always re-set a custom proxy -- it might have changed, particularly
       // password
-      Cache.log.info("Setting custom proxy settings");
+      Cache.info("Setting custom proxy settings");
       boolean proxyAuthSet = Cache.getDefault("PROXY_AUTH", false);
       Cache.setProxyProperties(Cache.getDefault("PROXY_SERVER", null),
               Cache.getDefault("PROXY_PORT", null),
@@ -1387,7 +1354,7 @@ public class Cache
               proxyAuthSet ? Cache.proxyAuthPassword : null, "localhost");
       break;
     default: // system proxy settings by default
-      Cache.log.info("Setting system proxy settings");
+      Cache.info("Setting system proxy settings");
       Cache.resetProxyProperties();
     }
   }
@@ -1586,73 +1553,174 @@ public class Cache
     }
   }
 
-  public final static int TRACE = 10;
+  public static void trace(String message)
+  {
+    if (initLogger())
+    {
+      log.trace(message, null);
+    }
+    else
+    {
+      System.out.println(message);
+    }
+  }
+
+  public static void trace(String message, Throwable t)
+  {
+    if (initLogger())
+    {
+      log.trace(message, t);
+    }
+    else
+    {
+      System.out.println(message);
+      t.printStackTrace();
+    }
+  }
+
+  public static void debug(String message)
+  {
+    if (initLogger())
+    {
+      log.debug(message, null);
+    }
+    else
+    {
+      System.out.println(message);
+    }
+
+  }
+
+  public static void debug(String message, Throwable t)
+  {
+    if (initLogger())
+    {
+      log.debug(message, t);
+    }
+    else
+    {
+      System.out.println(message);
+      t.printStackTrace();
+    }
+
+  }
 
-  public final static int DEBUG = 20;
+  public static void info(String message)
+  {
+    if (initLogger())
+    {
+      log.info(message, null);
+    }
+    else
+    {
+      System.out.println(message);
+    }
 
-  public final static int INFO = 30;
+  }
 
-  public final static int WARN = 40;
+  public static void info(String message, Throwable t)
+  {
+    if (initLogger())
+    {
+      log.info(message, t);
+    }
+    else
+    {
+      System.out.println(message);
+      t.printStackTrace();
+    }
 
-  public final static int ERROR = 50;
+  }
 
-  public static boolean println(int level, String message)
+  public static void warn(String message)
   {
-    if (Cache.log == null)
+    if (initLogger())
     {
-      if (level >= WARN)
-        System.err.println(message);
-      else if (level >= INFO)
-        System.out.println(message);
-      // not printing debug or trace messages
-      return false;
+      log.warn(message, null);
     }
-    if (level >= ERROR)
+    else
     {
-      Cache.log.error(message);
+      System.out.println(message);
     }
-    else if (level >= WARN)
+
+  }
+
+  public static void warn(String message, Throwable t)
+  {
+    if (initLogger())
     {
-      Cache.log.warn(message);
+      log.warn(message, t);
     }
-    else if (level >= INFO)
+    else
     {
-      Cache.log.info(message);
+      System.out.println(message);
+      t.printStackTrace();
     }
-    else if (level >= DEBUG)
+
+  }
+
+  public static void error(String message)
+  {
+    if (initLogger())
     {
-      Cache.log.debug(message);
+      log.error(message, null);
     }
     else
     {
-      Cache.log.trace(message);
+      System.err.println(message);
     }
-    return true;
+
   }
 
-  public static void trace(String message)
+  public static void error(String message, Throwable t)
   {
-    println(TRACE, message);
+    if (initLogger())
+    {
+      log.error(message, t);
+    }
+    else
+    {
+      System.err.println(message);
+      t.printStackTrace(System.err);
+    }
+
   }
 
-  public static void debug(String message)
+  public static void fatal(String message)
   {
-    println(DEBUG, message);
+    if (initLogger())
+    {
+      log.fatal(message, null);
+    }
+    else
+    {
+      System.err.println(message);
+    }
+
   }
 
-  public static void info(String message)
+  public static void fatal(String message, Throwable t)
   {
-    println(INFO, message);
+    if (initLogger())
+    {
+      log.fatal(message, t);
+    }
+    else
+    {
+      System.err.println(message);
+      t.printStackTrace(System.err);
+    }
+
   }
 
-  public static void warn(String message)
+  public static boolean isDebugEnabled()
   {
-    println(WARN, message);
+    return log == null ? false : log.isDebugEnabled();
   }
 
-  public static void error(String message)
+  public static boolean isTraceEnabled()
   {
-    println(ERROR, message);
+    return log == null ? false : log.isTraceEnabled();
   }
 
   /**