Merge branch '77-lifecycle-cleanup' into 'main'

Improve lifecycle and wakelock handling

Closes #73 and #77

See merge request !56

mailbox-android/src/main/java/org/briarproject/mailbox/android/MailboxService.kt

@@ -29,13 +29,13 @@ import androidx.core.content.ContextCompat
 import dagger.hilt.android.AndroidEntryPoint
 import org.briarproject.mailbox.android.MailboxNotificationManager.Companion.NOTIFICATION_MAIN_ID
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager
-import org.briarproject.mailbox.core.lifecycle.LifecycleManager.StartResult
-import org.briarproject.mailbox.core.lifecycle.LifecycleManager.StartResult.ALREADY_RUNNING
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager.StartResult.SUCCESS
+import org.briarproject.mailbox.core.system.AndroidWakeLock
 import org.briarproject.mailbox.core.system.AndroidWakeLockManager
 import org.slf4j.LoggerFactory.getLogger
 import java.util.concurrent.atomic.AtomicBoolean
 import javax.inject.Inject
+import kotlin.concurrent.thread
 import kotlin.system.exitProcess
 
 @AndroidEntryPoint
@@ -70,30 +70,39 @@ class MailboxService : Service() {
     @Inject
     internal lateinit var notificationManager: MailboxNotificationManager
 
+    private lateinit var lifecycleWakeLock: AndroidWakeLock
+
     override fun onCreate() {
         super.onCreate()
 
         LOG.info("Created")
         if (created.getAndSet(true)) {
             LOG.warn("Already created")
-            // FIXME when can this happen? Next line will kill app
+            // This is a canary to notify us about strange behavior concerning service creation
+            // in logs and bug reports. Calling stopSelf() kills the app.
             stopSelf()
             return
         }
 
-        // Hold a wake lock during startup
-        wakeLockManager.runWakefully({
         startForeground(NOTIFICATION_MAIN_ID, notificationManager.serviceNotification)
+
+        // We hold a wake lock during the whole lifecycle. We have a one-to-one relationship
+        // between MailboxService and the LifecycleManager. As we do not support lifecycle restarts
+        // only a single MailboxService is allowed to start and stop with the LifecycleManager
+        // singleton. Should the service be killed and restarted, the LifecycleManager must also
+        // have been destroyed and there is no way to recover except via a restart of the app.
+        // So should a second MailboxService be started anytime, this is a unrecoverable situation
+        // and we stop the app.
+        // Acquiring the wakelock here and releasing it as the last thing before exitProcess()
+        // during onDestroy() makes sure it is being held during the whole lifecycle.
+        lifecycleWakeLock = wakeLockManager.createWakeLock("Lifecycle")
+        lifecycleWakeLock.acquire()
+
         // Start the services in a background thread
-            wakeLockManager.executeWakefully({
-                val result: StartResult = lifecycleManager.startServices()
+        thread {
+            val result = lifecycleManager.startServices()
             when {
                 result === SUCCESS -> started = true
-                    result === ALREADY_RUNNING -> {
-                        LOG.warn("Already running")
-                        // FIXME when can this happen? Next line will kill app
-                        stopSelf()
-                    }
                 else -> {
                     if (LOG.isWarnEnabled) LOG.warn("Startup failed: $result")
                     // TODO: implement this
@@ -102,7 +111,7 @@ class MailboxService : Service() {
                     stopSelf()
                 }
             }
-            }, "LifecycleStartup")
+        }
         // Register for device shutdown broadcasts
         receiver = object : BroadcastReceiver() {
             override fun onReceive(context: Context, intent: Intent) {
@@ -115,7 +124,6 @@ class MailboxService : Service() {
         filter.addAction("android.intent.action.QUICKBOOT_POWEROFF")
         filter.addAction("com.htc.intent.action.QUICKBOOT_POWEROFF")
         registerReceiver(receiver, filter)
-        }, "LifecycleStartup")
     }
 
     override fun onBind(intent: Intent): IBinder? {
@@ -123,23 +131,23 @@ class MailboxService : Service() {
     }
 
     override fun onDestroy() {
-        wakeLockManager.runWakefully({
         super.onDestroy()
         LOG.info("Destroyed")
         stopForeground(true)
         if (receiver != null) unregisterReceiver(receiver)
-            wakeLockManager.executeWakefully({
-                try {
         if (started) {
+            try {
                 lifecycleManager.stopServices()
                 lifecycleManager.waitForShutdown()
-                    }
             } catch (e: InterruptedException) {
                 LOG.info("Interrupted while waiting for shutdown")
             }
+        }
+        // Do not exit within wakeful execution, otherwise we will never release the wake locks.
+        // Or maybe we want to do precisely that to make sure exiting really happens and the app
+        // doesn't get suspended before it gets a chance to exit?
+        lifecycleWakeLock.release()
         LOG.info("Exiting")
         exitProcess(0)
-            }, "LifecycleShutdown")
-        }, "LifecycleShutdown")
     }
 }

mailbox-android/src/main/java/org/briarproject/mailbox/android/MailboxViewModel.kt

@@ -30,9 +30,9 @@ import kotlinx.coroutines.flow.StateFlow
 import org.briarproject.android.dontkillmelib.DozeHelper
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager.LifecycleState
-import org.briarproject.mailbox.core.system.AndroidWakeLockManager
 import org.briarproject.mailbox.core.system.DozeWatchdog
 import javax.inject.Inject
+import kotlin.concurrent.thread
 
 @HiltViewModel
 class MailboxViewModel @Inject constructor(
@@ -41,7 +41,6 @@ class MailboxViewModel @Inject constructor(
     private val dozeWatchdog: DozeWatchdog,
     handle: SavedStateHandle,
     private val lifecycleManager: LifecycleManager,
-    private val wakeLockManager: AndroidWakeLockManager,
 ) : AndroidViewModel(app) {
 
     val needToShowDoNotKillMeFragment get() = dozeHelper.needToShowDoNotKillMeFragment(app)
@@ -68,10 +67,11 @@ class MailboxViewModel @Inject constructor(
     }
 
     fun wipe() {
-        wakeLockManager.executeWakefully({
+        thread {
+            // TODO: handle return value
             lifecycleManager.wipeMailbox()
             MailboxService.stopService(getApplication())
-        }, "LifecycleWipe")
+        }
     }
 
     fun getAndResetDozeFlag() = dozeWatchdog.andResetDozeFlag

mailbox-android/src/main/java/org/briarproject/mailbox/core/system/AndroidTaskScheduler.java

@@ -63,7 +63,6 @@ public class AndroidTaskScheduler implements TaskScheduler, Service {
 	private static final long ALARM_MS = INTERVAL_FIFTEEN_MINUTES;
 
 	private final Application app;
-	private final AndroidWakeLockManager wakeLockManager;
 	private final ScheduledExecutorService scheduledExecutorService;
 	private final AlarmManager alarmManager;
 
@@ -72,10 +71,8 @@ public class AndroidTaskScheduler implements TaskScheduler, Service {
 	private final Queue<ScheduledTask> tasks = new PriorityQueue<>();
 
 	AndroidTaskScheduler(Application app,
-			AndroidWakeLockManager wakeLockManager,
 			ScheduledExecutorService scheduledExecutorService) {
 		this.app = app;
-		this.wakeLockManager = wakeLockManager;
 		this.scheduledExecutorService = scheduledExecutorService;
 		alarmManager = (AlarmManager) requireNonNull(
 				app.getSystemService(ALARM_SERVICE));
@@ -107,7 +104,6 @@ public class AndroidTaskScheduler implements TaskScheduler, Service {
 	}
 
 	public void onAlarm(Intent intent) {
-		wakeLockManager.runWakefully(() -> {
 		int extraPid = intent.getIntExtra(EXTRA_PID, -1);
 		int currentPid = Process.myPid();
 		if (extraPid == currentPid) {
@@ -116,20 +112,17 @@ public class AndroidTaskScheduler implements TaskScheduler, Service {
 			runDueTasks();
 		} else {
 			info(LOG, () -> "Ignoring alarm with PID " + extraPid +
-						", current PID is " +
-						currentPid);
+					", current PID is " + currentPid);
 		}
-		}, "TaskAlarm");
 	}
 
 	private Cancellable schedule(Runnable task, Executor executor, long delay,
 			TimeUnit unit, AtomicBoolean cancelled) {
 		long now = SystemClock.elapsedRealtime();
 		long dueMillis = now + MILLISECONDS.convert(delay, unit);
-		Runnable wakeful = () ->
-				wakeLockManager.executeWakefully(task, executor, "TaskHandoff");
+		Runnable wrapped = () -> executor.execute(task);
 		Future<?> check = scheduleCheckForDueTasks(delay, unit);
-		ScheduledTask s = new ScheduledTask(wakeful, dueMillis, check,
+		ScheduledTask s = new ScheduledTask(wrapped, dueMillis, check,
 				cancelled);
 		synchronized (lock) {
 			tasks.add(s);
@@ -149,9 +142,8 @@ public class AndroidTaskScheduler implements TaskScheduler, Service {
 	}
 
 	private Future<?> scheduleCheckForDueTasks(long delay, TimeUnit unit) {
-		Runnable wakeful = () -> wakeLockManager.runWakefully(
-				this::runDueTasks, "TaskScheduler");
-		return scheduledExecutorService.schedule(wakeful, delay, unit);
+		return scheduledExecutorService
+				.schedule(this::runDueTasks, delay, unit);
 	}
 
 	@Wakeful

mailbox-android/src/main/java/org/briarproject/mailbox/core/system/AndroidTaskSchedulerModule.java

@@ -43,7 +43,7 @@ public class AndroidTaskSchedulerModule {
 			AndroidWakeLockManager wakeLockManager,
 			ScheduledExecutorService scheduledExecutorService) {
 		AndroidTaskScheduler scheduler = new AndroidTaskScheduler(app,
-				wakeLockManager, scheduledExecutorService);
+				scheduledExecutorService);
 		lifecycleManager.registerService(scheduler);
 		return scheduler;
 	}

mailbox-android/src/main/java/org/briarproject/mailbox/core/system/AndroidWakeLockManager.java

@@ -19,8 +19,6 @@
 
 package org.briarproject.mailbox.core.system;
 
-import java.util.concurrent.Executor;
-
 public interface AndroidWakeLockManager {
 
 	/**
@@ -28,27 +26,4 @@ public interface AndroidWakeLockManager {
 	 * logging; the underlying OS wake lock will use its own tag.
 	 */
 	AndroidWakeLock createWakeLock(String tag);
-
-	/**
-	 * Runs the given task while holding a wake lock.
-	 */
-	void runWakefully(Runnable r, String tag);
-
-	/**
-	 * Submits the given task to the given executor while holding a wake lock.
-	 * The lock is released when the task completes, or if an exception is
-	 * thrown while submitting or running the task.
-	 */
-	void executeWakefully(Runnable r, Executor executor, String tag);
-
-	/**
-	 * Starts a dedicated thread to run the given task asynchronously. A wake
-	 * lock is acquired before starting the thread and released when the task
-	 * completes, or if an exception is thrown while starting the thread or
-	 * running the task.
-	 * <p>
-	 * This method should only be used for lifecycle management tasks that
-	 * can't be run on an executor.
-	 */
-	void executeWakefully(Runnable r, String tag);
 }

mailbox-android/src/main/java/org/briarproject/mailbox/core/system/AndroidWakeLockManagerImpl.java

@@ -24,7 +24,6 @@ import android.content.Context;
 import android.content.pm.PackageManager;
 import android.os.PowerManager;
 
-import java.util.concurrent.Executor;
 import java.util.concurrent.ScheduledExecutorService;
 
 import javax.inject.Inject;
@@ -66,57 +65,6 @@ class AndroidWakeLockManagerImpl implements AndroidWakeLockManager {
 		return new AndroidWakeLockImpl(sharedWakeLock, tag);
 	}
 
-	@Override
-	public void runWakefully(Runnable r, String tag) {
-		AndroidWakeLock wakeLock = createWakeLock(tag);
-		wakeLock.acquire();
-		try {
-			r.run();
-		} finally {
-			wakeLock.release();
-		}
-	}
-
-	@Override
-	public void executeWakefully(Runnable r, Executor executor, String tag) {
-		AndroidWakeLock wakeLock = createWakeLock(tag);
-		wakeLock.acquire();
-		try {
-			executor.execute(() -> {
-				try {
-					r.run();
-				} finally {
-					// Release the wake lock if the task throws an exception
-					wakeLock.release();
-				}
-			});
-		} catch (Exception e) {
-			// Release the wake lock if the executor throws an exception when
-			// we submit the task (in which case the release() call above won't
-			// happen)
-			wakeLock.release();
-			throw e;
-		}
-	}
-
-	@Override
-	public void executeWakefully(Runnable r, String tag) {
-		AndroidWakeLock wakeLock = createWakeLock(tag);
-		wakeLock.acquire();
-		try {
-			new Thread(() -> {
-				try {
-					r.run();
-				} finally {
-					wakeLock.release();
-				}
-			}).start();
-		} catch (Exception e) {
-			wakeLock.release();
-			throw e;
-		}
-	}
-
 	private String getWakeLockTag(Context ctx) {
 		PackageManager pm = ctx.getPackageManager();
 		if (isInstalled(pm, "com.huawei.powergenie")) {

mailbox-core/src/main/java/org/briarproject/mailbox/core/db/JdbcDatabase.kt

@@ -124,7 +124,7 @@ abstract class JdbcDatabase(private val dbTypes: DatabaseTypes, private val cloc
             listener?.onDatabaseCompaction()
             val start: Long = now()
             compactAndClose()
-            logDuration(LOG, { "Compacting database" }, start)
+            logDuration(LOG, start) { "Compacting database" }
             // Allow the next transaction to reopen the DB
             connectionsLock.lock()
             try {
@@ -210,10 +210,10 @@ abstract class JdbcDatabase(private val dbTypes: DatabaseTypes, private val cloc
         val start = now()
         if (readOnly) {
             lock.readLock().lock()
-            logDuration(LOG, { "Waiting for read lock" }, start)
+            logDuration(LOG, start) { "Waiting for read lock" }
         } else {
             lock.writeLock().lock()
-            logDuration(LOG, { "Waiting for write lock" }, start)
+            logDuration(LOG, start) { "Waiting for write lock" }
         }
         return try {
             Transaction(startTransaction(), readOnly)

mailbox-core/src/main/java/org/briarproject/mailbox/core/lifecycle/LifecycleManager.java

@@ -38,7 +38,6 @@ public interface LifecycleManager {
 	 * The result of calling {@link #startServices()}.
 	 */
 	enum StartResult {
-		ALREADY_RUNNING,
 		SERVICE_ERROR,
 		SUCCESS
 	}

mailbox-core/src/main/java/org/briarproject/mailbox/core/lifecycle/LifecycleManagerImpl.kt

@@ -35,7 +35,6 @@ import org.briarproject.mailbox.core.lifecycle.LifecycleManager.LifecycleState.S
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager.LifecycleState.WIPING
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager.OpenDatabaseHook
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager.StartResult
-import org.briarproject.mailbox.core.lifecycle.LifecycleManager.StartResult.ALREADY_RUNNING
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager.StartResult.SERVICE_ERROR
 import org.briarproject.mailbox.core.lifecycle.LifecycleManager.StartResult.SUCCESS
 import org.briarproject.mailbox.core.setup.WipeManager
@@ -85,33 +84,37 @@ internal class LifecycleManagerImpl @Inject constructor(
     }
 
     override fun registerService(s: Service) {
-        LOG.info { "Registering service ${s.javaClass.simpleName}" }
+        LOG.info { "Registering service ${s.name()}" }
         services.add(s)
     }
 
     override fun registerOpenDatabaseHook(hook: OpenDatabaseHook) {
-        LOG.info { "Registering open database hook ${hook.javaClass.simpleName}" }
+        LOG.info { "Registering open database hook ${hook.name()}" }
         openDatabaseHooks.add(hook)
     }
 
     override fun registerForShutdown(e: ExecutorService) {
-        LOG.info { "Registering executor ${e.javaClass.simpleName}" }
+        LOG.info { "Registering executor ${e.name()}" }
         executors.add(e)
     }
 
     @GuardedBy("startStopWipeSemaphore")
     override fun startServices(): StartResult {
-        if (!startStopWipeSemaphore.tryAcquire()) {
-            LOG.info("Already starting or stopping")
-            return ALREADY_RUNNING
+        try {
+            startStopWipeSemaphore.acquire()
+        } catch (e: InterruptedException) {
+            LOG.warn("Interrupted while waiting to start services")
+            return SERVICE_ERROR
+        }
+        if (!state.compareAndSet(NOT_STARTED, STARTING)) {
+            return SERVICE_ERROR
         }
-        state.compareAndSet(NOT_STARTED, STARTING)
         return try {
             LOG.info("Opening database")
             var start = now()
             val reopened = db.open(this)
-            if (reopened) logDuration(LOG, { "Reopening database" }, start)
-            else logDuration(LOG, { "Creating database" }, start)
+            if (reopened) logDuration(LOG, start) { "Reopening database" }
+            else logDuration(LOG, start) { "Creating database" }
             // Inform hooks that DB was opened
             db.write { txn ->
                 for (hook in openDatabaseHooks) {
@@ -124,7 +127,7 @@ internal class LifecycleManagerImpl @Inject constructor(
             for (s in services) {
                 start = now()
                 s.startService()
-                logDuration(LOG, { "Starting service  ${s.javaClass.simpleName}" }, start)
+                logDuration(LOG, start) { "Starting service  ${s.name()}" }
             }
             state.compareAndSet(STARTING_SERVICES, RUNNING)
             startupLatch.countDown()
@@ -166,15 +169,10 @@ internal class LifecycleManagerImpl @Inject constructor(
             val wiped = state.value == WIPING
             LOG.info("Stopping services")
             state.value = STOPPING
-            for (s in services) {
-                val start = now()
-                s.stopService()
-                logDuration(LOG, { "Stopping service " + s.javaClass.simpleName }, start)
-            }
-            for (e in executors) {
-                LOG.trace { "Stopping executor ${e.javaClass.simpleName}" }
-                e.shutdownNow()
-            }
+
+            stopAllServices()
+            stopAllExecutors()
+
             if (wiped) {
                 // If we just wiped, the database has already been closed, so we should not call
                 // close(). Since the services are being shut down after wiping (so that the web
@@ -182,21 +180,40 @@ internal class LifecycleManagerImpl @Inject constructor(
                 // API call created some files in the meantime. To make sure we delete those in
                 // case of a wipe, repeat deletion of files here after the services have been
                 // stopped.
-                wipeManager.wipe(wipeDatabase = false)
+                run("wiping files again") {
+                    wipeManager.wipeFilesOnly()
+                }
             } else {
-                val start = now()
+                run("closing database") {
                     db.close()
-                logDuration(LOG, { "Closing database" }, start)
                 }
+            }
+
             shutdownLatch.countDown()
-        } catch (e: ServiceException) {
-            logException(LOG, e)
         } finally {
             state.compareAndSet(STOPPING, STOPPED)
             startStopWipeSemaphore.release()
         }
     }
 
+    @GuardedBy("startStopWipeSemaphore")
+    private fun stopAllServices() {
+        for (s in services) {
+            run("stopping service ${s.name()}") {
+                s.stopService()
+            }
+        }
+    }
+
+    @GuardedBy("startStopWipeSemaphore")
+    private fun stopAllExecutors() {
+        for (e in executors) {
+            run("stopping executor ${e.name()}") {
+                e.shutdownNow()
+            }
+        }
+    }
+
     @GuardedBy("startStopWipeSemaphore")
     override fun wipeMailbox(): Boolean {
         try {
@@ -209,8 +226,9 @@ internal class LifecycleManagerImpl @Inject constructor(
             return false
         }
         try {
-            wipeManager.wipe(wipeDatabase = true)
-
+            run("wiping database and files") {
+                wipeManager.wipeDatabaseAndFiles()
+            }
             // We need to move this to a thread so that the webserver call can finish when it calls
             // this. Otherwise we'll end up in a deadlock: the same thread trying to stop the
             // webserver from within a call that wants to send a response on the very same webserver.
@@ -219,7 +237,6 @@ internal class LifecycleManagerImpl @Inject constructor(
             thread {
                 stopServices()
             }
-
             return true
         } finally {
             startStopWipeSemaphore.release()
@@ -227,25 +244,28 @@ internal class LifecycleManagerImpl @Inject constructor(
     }
 
     @Throws(InterruptedException::class)
-    override fun waitForDatabase() {
-        dbLatch.await()
-    }
+    override fun waitForDatabase() = dbLatch.await()
 
     @Throws(InterruptedException::class)
-    override fun waitForStartup() {
-        startupLatch.await()
-    }
+    override fun waitForStartup() = startupLatch.await()
 
     @Throws(InterruptedException::class)
-    override fun waitForShutdown() {
-        shutdownLatch.await()
-    }
+    override fun waitForShutdown() = shutdownLatch.await()
 
-    override fun getLifecycleState(): LifecycleState {
-        return state.value
-    }
+    override fun getLifecycleState() = state.value
 
-    override fun getLifecycleStateFlow(): StateFlow<LifecycleState> {
-        return state
+    override fun getLifecycleStateFlow(): StateFlow<LifecycleState> = state
+
+    private fun run(name: String, task: () -> Unit) {
+        LOG.trace { name }
+        val start = now()
+        try {
+            task()
+        } catch (throwable: Throwable) {
+            logException(LOG, throwable) { "Error while $name" }
         }
+        logDuration(LOG, start) { name }
+    }
+
+    private fun Any.name() = javaClass.simpleName
 }

mailbox-core/src/main/java/org/briarproject/mailbox/core/setup/WipeManager.kt

@@ -42,12 +42,17 @@ class WipeManager @Inject constructor(
     /*
      * This must only be called by the LifecycleManager
      */
-    fun wipe(wipeDatabase: Boolean) {
-        if (wipeDatabase) {
+    fun wipeDatabaseAndFiles() {
         db.dropAllTablesAndClose()
         val dir = databaseConfig.getDatabaseDirectory()
         IoUtils.deleteFileOrDir(dir)
+        fileManager.deleteAllFiles()
     }
+
+    /*
+     * This must only be called by the LifecycleManager
+     */
+    fun wipeFilesOnly() {
         fileManager.deleteAllFiles()
     }
 

mailbox-core/src/main/java/org/briarproject/mailbox/core/util/LogUtils.kt

@@ -68,13 +68,18 @@ object LogUtils {
      * @param start  the start time of the task, as returned by [now]
      */
     @JvmStatic
-    fun logDuration(logger: Logger, msg: () -> String, start: Long) {
+    fun logDuration(logger: Logger, start: Long, msg: () -> String) {
         logger.trace {
             val duration = now() - start
             "${msg()} took $duration ms"
         }
     }
 
+    @JvmStatic
+    fun logException(logger: Logger, t: Throwable, message: () -> String) {
+        if (logger.isWarnEnabled) logger.warn(message(), t)
+    }
+
     @JvmStatic
     fun logException(logger: Logger, t: Throwable) {
         if (logger.isWarnEnabled) logger.warn(t.toString(), t)