[WIP] Use jcabi-log to reduce startup time

build.gradle

@@ -121,16 +121,18 @@ dependencies {
     compile 'de.jensd:fontawesomefx-materialdesignfont:1.7.22-4'
     compile 'org.fxmisc.richtext:richtextfx:0.7-M5'
 
-
+    // Logging
     compile 'commons-logging:commons-logging:1.2'
+    compile 'org.apache.logging.log4j:log4j-jcl:2.8.2'
+    compile 'org.apache.logging.log4j:log4j-api:2.8.2'
+    compile 'org.apache.logging.log4j:log4j-core:2.8.2'
+    compile 'com.jcabi:jcabi-log:0.17.2'
+    compile 'org.slf4j:slf4j-jcl:1.7.25' // required by jcabi-log to enable logging over jcl
 
     compile 'org.jsoup:jsoup:1.10.3'
     compile 'com.mashape.unirest:unirest-java:1.4.9'
     compile 'info.debatty:java-string-similarity:0.24'
 
-    compile 'org.apache.logging.log4j:log4j-jcl:2.8.2'
-    compile 'org.apache.logging.log4j:log4j-api:2.8.2'
-    compile 'org.apache.logging.log4j:log4j-core:2.8.2'
     compile 'org.xmlunit:xmlunit-core:2.3.0'
     compile 'org.xmlunit:xmlunit-matchers:2.3.0'
 

docs/adr/0000-use-architectural-decision-records.md

@@ -0,0 +1,16 @@
+# Use Architectural Decision Records
+
+We need to record the architectural decisions made on this project.
+
+## Considered Alternatives
+
+* No record
+* [DecisionRecord](https://github.com/schubmat/DecisionCapture)
+* [Michael Nygard's template](http://thinkrelevance.com/blog/2011/11/15/documenting-architecture-decisions), maintainable by [adr-tools](https://github.com/npryce/adr-tools)
+* [Sustainable Architectural Decisions](https://www.infoq.com/articles/sustainable-architectural-design-decisions)
+* [Other templates](https://github.com/joelparkerhenderson/architecture_decision_record)
+
+## Conclusion
+
+* *Chosen Alternative: Decision Record*
+* That template is lean and fits most the development style

docs/adr/0001-use-jcabi-log.md

@@ -0,0 +1,15 @@
+# Use jcabi-log
+
+We need to reduce startup time of JabRef (https://github.com/JabRef/jabref/issues/2966).
+One time consuming aspect is the logging
+
+## Considered Alternatives
+
+* [jcabi-log](http://log.jcabi.com/)
+* [TinyLog](http://www.tinylog.org/)
+
+## Conclusion
+
+* Chosen Alternative: jcabi-log (see https://github.com/JabRef/jabref/pull/3015)
+* org.jabref.gui.logging.GuiAppender strongly relies on Apache Log4j2.
+  TinyLog does not support mirroring log outputs and thus we cannot easily switch to TinyLog.

docs/adr/index.md

@@ -0,0 +1,7 @@
+# Architectural Decision Records
+
+This lists the architectural decisions for JabRef.
+
+- [0000-use-architectural-decision-records.md](0000-use-architectural-decision-records) - Use Architectural Decision Records
+- [0001-use-jcabi-log.md](0000-use-jcabi-log) - Use [jcabi-log](http://log.jcabi.com/)
+- [template.md](template/) - the template

docs/adr/template.md

@@ -0,0 +1,36 @@
+# <Short Title of the Issue>
+
+**UserStory:** <TICKET/ISSUE-NUMBER>
+
+<WRITE ONE SENTENCE DESCRIBING THE PROBLEM. (Optional)>
+
+## Considered Alternatives
+
+* <ALTERNATIVE 1>
+* <ALTERNATIVE 2>
+* <ALTERNATIVE 3>
+
+## Conclusion
+
+* *Chosen Alternative: <ALTERNATIVE 1>*
+* <FURTHER RATIONALE (Optional)>
+
+## Comparison (Optional)
+
+### <ALTERNATIVE 1>
+
+* + <ARGUMENT 1 PRO>
+* + <ARGUMENT 2 PRO>
+* - <ARGUMENT 1 CONTRA>
+
+### <ALTERNATIVE 2>
+
+* + <ARGUMENT 1 PRO>
+* + <ARGUMENT 2 PRO>
+* - <ARGUMENT 1 CONTRA>
+
+### <ALTERNATIVE 3>
+
+* + <ARGUMENT 1 PRO>
+* + <ARGUMENT 2 PRO>
+* - <ARGUMENT 1 CONTRA>

src/main/java/org/jabref/JabRefException.java

@@ -1,11 +1,7 @@
 package org.jabref;
 
-import org.apache.commons.logging.Log;
-import org.apache.commons.logging.LogFactory;
-
 public class JabRefException extends Exception {
 
-    private static final Log LOGGER = LogFactory.getLog(JabRefException.class);
     private String localizedMessage;
 
     public JabRefException(String message) {
@@ -33,7 +29,7 @@ public JabRefException(Throwable cause) {
     @Override
     public String getLocalizedMessage() {
         if (localizedMessage == null) {
-            LOGGER.debug("No localized message exception message defined. Falling back to getMessage().");
+            Logger.debug(this, "No localized message exception message defined. Falling back to getMessage().");
             return getMessage();
         } else {
             return localizedMessage;

src/main/java/org/jabref/JabRefExecutorService.java

@@ -9,17 +9,12 @@
 import java.util.concurrent.Executors;
 import java.util.concurrent.Future;
 
-import org.apache.commons.logging.Log;
-import org.apache.commons.logging.LogFactory;
-
-
 /**
  * Responsible for managing of all threads (except Swing threads) in JabRef
  */
 public class JabRefExecutorService implements Executor {
 
     public static final JabRefExecutorService INSTANCE = new JabRefExecutorService();
-    private static final Log LOGGER = LogFactory.getLog(JabRefExecutorService.class);
     private final ExecutorService executorService = Executors.newCachedThreadPool(r -> {
         Thread thread = new Thread(r);
         thread.setName("JabRef CachedThreadPool");
@@ -41,7 +36,7 @@ private JabRefExecutorService() { }
     @Override
     public void execute(Runnable command) {
         if (command == null) {
-            LOGGER.debug("Received null as command for execution");
+            Logger.debug(this, "Received null as command for execution");
             return;
         }
 
@@ -50,7 +45,7 @@ public void execute(Runnable command) {
 
     public void executeAndWait(Runnable command) {
         if (command == null) {
-            LOGGER.debug("Received null as command for execution");
+            Logger.debug(this, "Received null as command for execution");
             return;
         }
 
@@ -62,14 +57,14 @@ public void executeAndWait(Runnable command) {
             } catch (InterruptedException ignored) {
                 // Ignored
             } catch (ExecutionException e) {
-                LOGGER.error("Problem executing command", e);
+                Logger.error(this, "Problem executing command", e);
             }
         }
     }
 
     public boolean executeAndWait(Callable command) {
         if (command == null) {
-            LOGGER.debug("Received null as command for execution");
+            Logger.debug(this, "Received null as command for execution");
             return false;
         }
 
@@ -81,7 +76,7 @@ public boolean executeAndWait(Callable command) {
             } catch (InterruptedException ignored) {
                 // Ignored
             } catch (ExecutionException e) {
-                LOGGER.error("Problem executing command", e);
+                Logger.error(this, "Problem executing command", e);
                 return false;
             }
         }
@@ -97,7 +92,7 @@ public void executeInterruptableTask(final Runnable runnable, String taskName) {
 
     public void executeInterruptableTaskAndWait(Runnable runnable) {
         if (runnable == null) {
-            LOGGER.debug("Received null as command for execution");
+            Logger.debug(this, "Received null as command for execution");
             return;
         }
 
@@ -109,7 +104,7 @@ public void executeInterruptableTaskAndWait(Runnable runnable) {
             } catch (InterruptedException ignored) {
                 // Ignored
             } catch (ExecutionException e) {
-                LOGGER.error("Problem executing command", e);
+                Logger.error(this, "Problem executing command", e);
             }
         }
     }

src/main/java/org/jabref/JabRefGUI.java

@@ -37,11 +37,8 @@
 
 import com.jgoodies.looks.plastic.Plastic3DLookAndFeel;
 import com.jgoodies.looks.plastic.theme.SkyBluer;
-import org.apache.commons.logging.Log;
-import org.apache.commons.logging.LogFactory;
 
 public class JabRefGUI {
-    private static final Log LOGGER = LogFactory.getLog(JabRefGUI.class);
 
     private static JabRefFrame mainFrame;
 
@@ -96,7 +93,7 @@ private void openWindow() {
 
         GUIGlobals.init();
 
-        LOGGER.debug("Initializing frame");
+        Logger.debug(this, "Initializing frame");
         JabRefGUI.mainFrame = new JabRefFrame();
 
         // Add all bibDatabases databases to the frame:
@@ -120,7 +117,7 @@ private void openWindow() {
                         pr.getDatabaseContext().clearDatabaseFile(); // do not open the original file
                         pr.getDatabase().clearSharedDatabaseID();
 
-                        LOGGER.error("Connection error", e);
+                        Logger.error(this, "Connection error", e);
                         JOptionPane.showMessageDialog(mainFrame,
                                 e.getMessage() + "\n\n" + Localization.lang("A local copy will be opened."),
                                 Localization.lang("Connection error"), JOptionPane.WARNING_MESSAGE);
@@ -182,7 +179,7 @@ private void openWindow() {
             OpenDatabaseAction.performPostOpenActions(panel, pr);
         }
 
-        LOGGER.debug("Finished adding panels");
+        Logger.debug(this, "Finished adding panels");
 
         if (!bibDatabases.isEmpty()) {
             JabRefGUI.getMainFrame().getCurrentBasePanel().getMainTable().requestFocus();
@@ -211,7 +208,7 @@ private void openLastEditedDatabases() {
                     Globals.prefs.getImportFormatPreferences());
 
             if (parsedDatabase.isEmpty()) {
-                LOGGER.error(Localization.lang("Error opening file") + " '" + dbFile.getPath() + "'");
+                Logger.error(this, Localization.lang("Error opening file") + " '" + dbFile.getPath() + "'");
             } else {
                 bibDatabases.add(parsedDatabase);
             }
@@ -238,7 +235,7 @@ private void setLookAndFeel() {
                 if (System.getProperty("java.runtime.name").contains("OpenJDK")) {
                     // Metal L&F
                     lookFeel = UIManager.getCrossPlatformLookAndFeelClassName();
-                    LOGGER.warn(
+                    Logger.warn(this,
                             "There seem to be problems with OpenJDK and the default GTK Look&Feel. Using Metal L&F instead. Change to another L&F with caution.");
                 } else {
                     lookFeel = systemLookFeel;
@@ -269,11 +266,11 @@ private void setLookAndFeel() {
                             Localization
                                     .lang("Unable to find the requested look and feel and thus the default one is used."),
                             Localization.lang("Warning"), JOptionPane.WARNING_MESSAGE);
-                    LOGGER.warn("Unable to find requested look and feel", e);
+                    Logger.warn(this, "Unable to find requested look and feel", e);
                 }
             }
         } catch (Exception e) {
-            LOGGER.warn("Look and feel could not be set", e);
+            Logger.warn(this, "Look and feel could not be set", e);
         }
 
         // In JabRef v2.8, we did it only on NON-Mac. Now, we try on all platforms