One more attempt at fixing dynamic logging reconfiguration

- moved out of GBApplication to class Logging
- the main thing is: when start()ing the FileAppender again, it *must*
- be configured to be non-lazy, otherwise it won't open the stream ever again.

app/build.gradle

@@ -6,6 +6,8 @@ def ABORT_ON_CHECK_FAILURE=false
 
 tasks.withType(Test) { systemProperty 'MiFirmwareDir', System.getProperty('MiFirmwareDir', null) }
 
+// sourceSets.test.runtimeClasspath += File('src/main/assets')
+
 android {
     compileSdkVersion 23
     buildToolsVersion "23.0.3"
@@ -42,6 +44,8 @@ android {
 }
 
 dependencies {
+//    testCompile 'ch.qos.logback:logback-classic:1.1.3'
+//    testCompile 'ch.qos.logback:logback-core:1.1.3'
     testCompile 'junit:junit:4.12'
     testCompile "org.mockito:mockito-core:1.9.5"
 
@@ -100,7 +104,6 @@ task pmd(type: Pmd) {
     }
 }
 
-
 task findbugs(type: FindBugs) {
     ignoreFailures = !ABORT_ON_CHECK_FAILURE
     effort = "default"

app/src/main/java/nodomain/freeyourgadget/gadgetbridge/GBApplication.java

@@ -20,9 +20,6 @@ import android.support.v4.content.LocalBroadcastManager;
 import android.util.Log;
 import android.util.TypedValue;
 
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
-
 import java.io.File;
 import java.io.IOException;
 import java.util.HashSet;
@@ -30,8 +27,6 @@ import java.util.concurrent.TimeUnit;
 import java.util.concurrent.locks.Lock;
 import java.util.concurrent.locks.ReentrantLock;
 
-import ch.qos.logback.classic.spi.ILoggingEvent;
-import ch.qos.logback.core.Appender;
 import nodomain.freeyourgadget.gadgetbridge.database.ActivityDatabaseHandler;
 import nodomain.freeyourgadget.gadgetbridge.database.DBConstants;
 import nodomain.freeyourgadget.gadgetbridge.database.DBHandler;
@@ -62,7 +57,6 @@ public class GBApplication extends Application {
     //if preferences have to be migrated, increment the following and add the migration logic in migratePrefs below; see http://stackoverflow.com/questions/16397848/how-can-i-migrate-android-preferences-with-a-new-version
     private static final int CURRENT_PREFS_VERSION = 2;
     private static LimitedQueue mIDSenderLookup = new LimitedQueue(16);
-    private static Appender<ILoggingEvent> fileLogger;
     private static Prefs prefs;
     private static GBPrefs gbPrefs;
     /**
@@ -72,6 +66,13 @@ public class GBApplication extends Application {
 
     public static final String ACTION_QUIT
             = "nodomain.freeyourgadget.gadgetbridge.gbapplication.action.quit";
+    private static Logging logging = new Logging() {
+        @Override
+        protected String createLogDirectory() throws IOException {
+            File dir = FileUtils.getExternalFilesDir();
+            return dir.getAbsolutePath();
+        }
+    };
     private final BroadcastReceiver mReceiver = new BroadcastReceiver() {
         @Override
         public void onReceive(Context context, Intent intent) {
@@ -114,11 +115,6 @@ public class GBApplication extends Application {
         }
 
         setupExceptionHandler();
-//        For debugging problems with the logback configuration
-//        LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
-//         print logback's internal status
-//        StatusPrinter.print(lc);
-//        Logger logger = LoggerFactory.getLogger(GBApplication.class);
 
         deviceService = createDeviceService();
         GB.environment = GBEnvironment.createDeviceEnvironment();
@@ -138,6 +134,10 @@ public class GBApplication extends Application {
 //        db.close();
     }
 
+    public static void setupLogging(boolean enabled) {
+        logging.setupLogging(enabled);
+    }
+
     private void setupExceptionHandler() {
         LoggingExceptionHandler handler = new LoggingExceptionHandler(Thread.getDefaultUncaughtExceptionHandler());
         Thread.setDefaultUncaughtExceptionHandler(handler);
@@ -147,71 +147,6 @@ public class GBApplication extends Application {
         return prefs.getBoolean("log_to_file", false);
     }
 
-    public static void setupLogging(boolean enable) {
-        try {
-            if (fileLogger == null) {
-                File dir = FileUtils.getExternalFilesDir();
-                // used by assets/logback.xml since the location cannot be statically determined
-                System.setProperty("GB_LOGFILES_DIR", dir.getAbsolutePath());
-                rememberFileLogger();
-            }
-            if (enable) {
-                startFileLogger();
-            } else {
-                stopFileLogger();
-            }
-            getLogger().info("Gadgetbridge version: " + BuildConfig.VERSION_NAME);
-        } catch (IOException ex) {
-            Log.e("GBApplication", "External files dir not available, cannot log to file", ex);
-            stopFileLogger();
-        }
-    }
-
-    private static void startFileLogger() {
-        if (fileLogger != null && !fileLogger.isStarted()) {
-            addFileLogger(fileLogger);
-            fileLogger.start();
-        }
-    }
-
-    private static void stopFileLogger() {
-        if (fileLogger != null && fileLogger.isStarted()) {
-            fileLogger.stop();
-            removeFileLogger(fileLogger);
-        }
-    }
-
-    private static void rememberFileLogger() {
-        ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
-        fileLogger = root.getAppender("FILE");
-    }
-
-    private static void addFileLogger(Appender<ILoggingEvent> fileLogger) {
-        try {
-            ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
-            if (!root.isAttached(fileLogger)) {
-                root.addAppender(fileLogger);
-            }
-        } catch (Throwable ex) {
-            Log.e("GBApplication", "Error adding logger FILE appender", ex);
-        }
-    }
-
-    private static void removeFileLogger(Appender<ILoggingEvent> fileLogger) {
-        try {
-            ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
-            if (root.isAttached(fileLogger)) {
-                root.detachAppender(fileLogger);
-            }
-        } catch (Throwable ex) {
-            Log.e("GBApplication", "Error removing logger FILE appender", ex);
-        }
-    }
-
-    private static Logger getLogger() {
-        return LoggerFactory.getLogger(GBApplication.class);
-    }
-
     public static Context getContext() {
         return context;
     }

app/src/main/java/nodomain/freeyourgadget/gadgetbridge/Logging.java

@@ -0,0 +1,128 @@
+package nodomain.freeyourgadget.gadgetbridge;
+
+import android.util.Log;
+
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+import java.io.IOException;
+
+import ch.qos.logback.classic.LoggerContext;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.Appender;
+import ch.qos.logback.core.FileAppender;
+import ch.qos.logback.core.encoder.Encoder;
+import ch.qos.logback.core.encoder.LayoutWrappingEncoder;
+import ch.qos.logback.core.util.StatusPrinter;
+
+public abstract class Logging {
+    public static final String PROP_LOGFILES_DIR = "GB_LOGFILES_DIR";
+
+    private FileAppender<ILoggingEvent> fileLogger;
+
+    public void setupLogging(boolean enable) {
+        try {
+            if (fileLogger == null) {
+                init();
+            }
+            if (enable) {
+                startFileLogger();
+            } else {
+                stopFileLogger();
+            }
+            getLogger().info("Gadgetbridge version: " + BuildConfig.VERSION_NAME);
+        } catch (IOException ex) {
+            Log.e("GBApplication", "External files dir not available, cannot log to file", ex);
+            stopFileLogger();
+        }
+    }
+
+    public void debugLoggingConfiguration() {
+        // For debugging problems with the logback configuration
+        LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
+        // print logback's internal status
+        StatusPrinter.print(lc);
+//        Logger logger = LoggerFactory.getLogger(Logging.class);
+    }
+
+    protected abstract String createLogDirectory() throws IOException;
+
+    protected void init() throws IOException {
+        String dir = createLogDirectory();
+        if (dir == null) {
+            throw new IllegalArgumentException("log directory must not be null");
+        }
+        // used by assets/logback.xml since the location cannot be statically determined
+        System.setProperty(PROP_LOGFILES_DIR, dir);
+        rememberFileLogger();
+    }
+
+    private Logger getLogger() {
+        return LoggerFactory.getLogger(Logging.class);
+    }
+
+    private void startFileLogger() {
+        if (fileLogger != null && !fileLogger.isStarted()) {
+            addFileLogger(fileLogger);
+            fileLogger.setLazy(false); // hack to make sure that start() actually opens the file
+            fileLogger.start();
+        }
+    }
+
+    private void stopFileLogger() {
+        if (fileLogger != null && fileLogger.isStarted()) {
+            fileLogger.stop();
+            removeFileLogger(fileLogger);
+        }
+    }
+
+    private void rememberFileLogger() {
+        ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
+        fileLogger = (FileAppender<ILoggingEvent>) root.getAppender("FILE");
+    }
+
+    private void addFileLogger(Appender<ILoggingEvent> fileLogger) {
+        try {
+            ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
+            if (!root.isAttached(fileLogger)) {
+                root.addAppender(fileLogger);
+            }
+        } catch (Throwable ex) {
+            Log.e("GBApplication", "Error adding logger FILE appender", ex);
+        }
+    }
+
+    private void removeFileLogger(Appender<ILoggingEvent> fileLogger) {
+        try {
+            ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
+            if (root.isAttached(fileLogger)) {
+                root.detachAppender(fileLogger);
+            }
+        } catch (Throwable ex) {
+            Log.e("GBApplication", "Error removing logger FILE appender", ex);
+        }
+    }
+
+    public FileAppender<ILoggingEvent> getFileLogger() {
+        return fileLogger;
+    }
+
+    public boolean setImmediateFlush(boolean enable) {
+        FileAppender<ILoggingEvent> fileLogger = getFileLogger();
+        Encoder<ILoggingEvent> encoder = fileLogger.getEncoder();
+        if (encoder instanceof LayoutWrappingEncoder) {
+            ((LayoutWrappingEncoder) encoder).setImmediateFlush(enable);
+            return true;
+        }
+        return false;
+    }
+
+    public boolean isImmediateFlush() {
+        FileAppender<ILoggingEvent> fileLogger = getFileLogger();
+        Encoder<ILoggingEvent> encoder = fileLogger.getEncoder();
+        if (encoder instanceof LayoutWrappingEncoder) {
+            return ((LayoutWrappingEncoder) encoder).isImmediateFlush();
+        }
+        return false;
+    }
+}

app/src/main/java/nodomain/freeyourgadget/gadgetbridge/util/FileUtils.java

@@ -182,4 +182,31 @@ public class FileUtils {
         }
         return out.toByteArray();
     }
+
+    public static boolean deleteRecursively(File dir) {
+        if (!dir.exists()) {
+            return true;
+        }
+        if (dir.isFile()) {
+            return dir.delete();
+        }
+        for (File sub : dir.listFiles()) {
+            if (!deleteRecursively(sub)) {
+                return false;
+            }
+        }
+        return dir.delete();
+    }
+
+    public static File createTempDir(String prefix) throws IOException {
+        File parent = new File(System.getProperty("java.io.tmpdir", "/tmp"));
+        for (int i = 1; i < 100; i++) {
+            String name = prefix + (int) (Math.random() * 100000);
+            File dir = new File(parent, name);
+            if (dir.mkdirs()) {
+                return dir;
+            }
+        }
+        throw new IOException("Cannot create temporary directory in " + parent);
+    }
 }

app/src/test/java/nodomain/freeyourgadget/gadgetbridge/test/LoggingTest.java

@@ -0,0 +1,87 @@
+package nodomain.freeyourgadget.gadgetbridge.test;
+
+import android.support.annotation.NonNull;
+
+import junit.framework.AssertionFailedError;
+
+import org.junit.After;
+import org.junit.BeforeClass;
+import org.junit.Test;
+
+import java.io.File;
+import java.io.IOException;
+
+import nodomain.freeyourgadget.gadgetbridge.Logging;
+import nodomain.freeyourgadget.gadgetbridge.util.FileUtils;
+
+import static junit.framework.Assert.assertEquals;
+import static junit.framework.Assert.assertFalse;
+import static junit.framework.Assert.assertNotNull;
+import static junit.framework.Assert.assertTrue;
+import static junit.framework.Assert.fail;
+
+public class LoggingTest {
+
+    @BeforeClass
+    public static void setupSuite() {
+        System.setProperty("logback.configurationFile", "logback.xml");
+    }
+
+    private Logging logging = new Logging() {
+        @Override
+        protected String createLogDirectory() throws IOException {
+            File dir = ensureLogFilesDir();
+            return dir.getAbsolutePath();
+        }
+
+        @NonNull
+        private File ensureLogFilesDir() throws IOException {
+            return FileUtils.createTempDir("logfiles");
+        }
+    };
+
+    @After
+    public void tearDown() {
+        assertTrue(FileUtils.deleteRecursively(getLogFilesDir()));
+    }
+
+    @NonNull
+    private File getLogFilesDir() {
+        String dirName = System.getProperty(Logging.PROP_LOGFILES_DIR);
+        if (dirName != null && dirName.length() > 5) {
+            File dir = new File(dirName);
+            return dir;
+        }
+        fail("Property " + Logging.PROP_LOGFILES_DIR + " has invalid value: " + dirName);
+        return null; // not reached
+    }
+
+    @Test
+    public void testToggleLogging() {
+        try {
+            File dir = getLogFilesDir();
+        } catch (AssertionFailedError ignored) {
+            // expected, as not yet set up
+        }
+
+        try {
+            logging.setupLogging(true);
+            File dir = getLogFilesDir();
+            assertEquals(1, dir.list().length);
+            assertNotNull(logging.getFileLogger());
+            assertTrue(logging.getFileLogger().isStarted());
+
+            logging.setupLogging(false);
+            assertNotNull(logging.getFileLogger());
+            assertFalse(logging.getFileLogger().isStarted());
+
+            logging.setupLogging(true);
+            assertNotNull(logging.getFileLogger());
+            assertTrue(logging.getFileLogger().isStarted());
+        } catch (AssertionFailedError ex) {
+            logging.debugLoggingConfiguration();
+            System.err.println(System.getProperty("java.class.path"));
+            throw ex;
+        }
+    }
+}