Merge pull request #2 from motorro/issue-1-logging

Issue 1 logging

README.md

@@ -3,6 +3,8 @@
 A wrapper for [Android AppUpdateManager](https://developer.android.com/reference/com/google/android/play/core/appupdate/AppUpdateManager) 
 to simplify in-app update flow.
 
+<!-- toc -->
+
 - [Features](#features)
 - [Basics](#basics)
 - [Using in your project](#using-in-your-project)
@@ -25,6 +27,11 @@ to simplify in-app update flow.
 - [Using library in multi-activity setup](#using-library-in-multi-activity-setup)
   * [AppUpdateManager instance](#appupdatemanager-instance)
   * [Use safe event handlers](#use-safe-event-handlers)
+- [Logging](#logging)
+  * [Enabling logger](#enabling-logger)
+  * [Logging rules](#logging-rules)
+
+<!-- tocstop -->
 
 ## Features
 -   A complete [lifecycle-aware component](https://developer.android.com/topic/libraries/architecture/lifecycle) to take
@@ -356,3 +363,45 @@ class App: Application() {
     }
 }
 ```
+
+## Logging
+Sometimes you'll want to see what is going on in the update flow. The library supports logging to 
+[Timber](https://github.com/JakeWharton/timber). 
+
+### Enabling logger
+The library itself does not plant any tree - you need to do it yourself to get log output:
+```kotlin
+class App: Application() {
+    override fun onCreate() {
+        super.onCreate()
+        if (BuildConfig.DEBUG) {
+            Timber.plant(Timber.DebugTree())
+        }
+    }
+}
+```
+
+### Logging rules
+*   All library log output has common tag prefix: `AUW`. 
+*   Checking for update and update results have `info` level.
+*   Update check failure and critical errors have `warning` level.
+*   Internals (state transition, lifecycle updates) have `debug` level.
+
+All-in-all the library log looks like this:
+```
+D/AUW::AppUpdateLifecycleStateMachine: State machine initialized
+D/AUW:startImmediateUpdate: Starting FLEXIBLE update flow...
+D/AUW::AppUpdateLifecycleStateMachine: Setting new state: Initial
+D/AUW::Initial: onStart
+D/AUW::AppUpdateLifecycleStateMachine: Setting new state: Checking
+D/AUW::AppUpdateLifecycleStateMachine: Starting new state...
+D/AUW::Checking: onStart
+D/AUW::IntervalBreaker: Last time cancelled: 0, Current time: 1565980326128, Enough time passed: yes
+I/AUW::Checking: Getting application update info for FLEXIBLE update...
+I/AUW::Checking: Application update info: Update info: 
+        - available version code: 62107400
+        - update availability: UPDATE_NOT_AVAILABLE
+        - install status: UNKNOWN
+        - update types allowed: NONE
+D/AUW::Checking: Evaluating update info...
+```

appupdatewrapper/build.gradle

@@ -76,6 +76,8 @@ dependencies {
     kapt 'androidx.lifecycle:lifecycle-compiler:2.2.0-alpha03'
     api 'com.google.android.play:core:1.6.1'
 
+    implementation 'com.jakewharton.timber:timber:4.7.1'
+
     testImplementation project(":testapp")
     testImplementation 'androidx.test:core:1.2.1-alpha02'
     testImplementation 'androidx.test.ext:junit:1.1.2-alpha02'

appupdatewrapper/src/main/java/com/motorro/appupdatewrapper/AppUpdateState.kt

@@ -15,13 +15,14 @@
 
 package com.motorro.appupdatewrapper
 
+import androidx.annotation.CallSuper
 import androidx.annotation.VisibleForTesting
 import com.google.android.play.core.appupdate.AppUpdateManager
 
 /**
  * Application update state interface
  */
-internal abstract class AppUpdateState: AppUpdateWrapper {
+internal abstract class AppUpdateState: AppUpdateWrapper, Tagged {
     /**
      * Update stateMachine
      * @see AppUpdateStateMachine.setUpdateState
@@ -49,6 +50,7 @@ internal abstract class AppUpdateState: AppUpdateWrapper {
         if(false != stateMachine.flowBreaker.isEnoughTimePassedSinceLatestCancel()) {
             block()
         } else {
+            timber.d("Update flow broken")
             complete()
         }
     }
@@ -60,6 +62,13 @@ internal abstract class AppUpdateState: AppUpdateWrapper {
         stateMachine.setUpdateState(state)
     }
 
+    /**
+     * Saves time user has explicitly cancelled update
+     */
+    protected fun markUserCancelTime() {
+        stateMachine.flowBreaker.saveTimeCanceled()
+    }
+
     /**
      * Sets a dummy state
      */
@@ -133,6 +142,7 @@ internal abstract class AppUpdateState: AppUpdateWrapper {
     /**
      * Called by state-machine when state is being replaced
      */
+    @CallSuper
     override fun cleanup() = Unit
 }
 
@@ -144,12 +154,14 @@ internal class None: AppUpdateState()
 /**
  * Completes the update sequence
  */
-internal class Done: AppUpdateState() {
+internal class Done: AppUpdateState(), Tagged {
     /**
      * Handles lifecycle `onResume`
      */
     override fun onResume() {
         super.onResume()
+        timber.d("onResume")
+        timber.d("Completing...")
         withUpdateView {
             updateComplete()
             setNone()
@@ -167,6 +179,8 @@ internal class Error(@VisibleForTesting val error: AppUpdateException) : AppUpda
      */
     override fun onResume() {
         super.onResume()
+        timber.d("onResume")
+        timber.w(error, "Application update failure: ")
         ifNotBroken {
             withUpdateView {
                 nonCriticalUpdateError(error)
@@ -186,6 +200,8 @@ internal class Failed(@VisibleForTesting val error: AppUpdateException) : AppUpd
      */
     override fun onResume() {
         super.onResume()
+        timber.d("onResume")
+        timber.w(error, "Application update failure: ")
         withUpdateView {
             updateFailed(error)
             setNone()

appupdatewrapper/src/main/java/com/motorro/appupdatewrapper/AppUpdateStateMachine.kt

@@ -59,7 +59,7 @@ internal class AppUpdateLifecycleStateMachine(
     override val updateManager: AppUpdateManager,
     override val view: AppUpdateView,
     override val flowBreaker: UpdateFlowBreaker = UpdateFlowBreaker.alwaysOn()
-): AppUpdateStateMachine, AppUpdateWrapper, LifecycleObserver {
+): AppUpdateStateMachine, AppUpdateWrapper, LifecycleObserver, Tagged {
     /**
      * Current update state
      */
@@ -69,22 +69,26 @@ internal class AppUpdateLifecycleStateMachine(
     init {
         currentUpdateState = None()
         lifecycle.addObserver(this)
+        timber.d("State machine initialized")
     }
 
     /**
      * Sets new update state
      */
     override fun setUpdateState(newState: AppUpdateState) {
+        timber.d("Setting new state: %s", newState.javaClass.simpleName)
         currentUpdateState.cleanup()
 
         newState.stateMachine = this
         currentUpdateState = newState
 
         with(lifecycle.currentState) {
             if (isAtLeast(Lifecycle.State.STARTED)) {
+                timber.d("Starting new state...")
                 newState.onStart()
             }
             if (isAtLeast(Lifecycle.State.RESUMED)) {
+                timber.d("Resuming new state...")
                 newState.onResume()
             }
         }
@@ -114,8 +118,12 @@ internal class AppUpdateLifecycleStateMachine(
      * Checks activity result and returns `true` if result is an update result and was handled
      * Use to check update activity result in [android.app.Activity.onActivityResult]
      */
-    override fun checkActivityResult(requestCode: Int, resultCode: Int): Boolean =
-        currentUpdateState.checkActivityResult(requestCode, resultCode)
+    override fun checkActivityResult(requestCode: Int, resultCode: Int): Boolean {
+        timber.d("Processing activity result: requestCode(%d), resultCode(%d)", requestCode, resultCode)
+        return currentUpdateState.checkActivityResult(requestCode, resultCode).also {
+            timber.d("Activity result handled: %b", it)
+        }
+    }
 
     /**
      * Cancels update installation
@@ -141,5 +149,6 @@ internal class AppUpdateLifecycleStateMachine(
     override fun cleanup() {
         lifecycle.removeObserver(this)
         currentUpdateState = None()
+        timber.d("Cleaned-up!")
     }
 }