Merge pull request #1283 from MarcelRobitaille/1275-add-logging

 Add logging to diagnose bugs in production

CHANGELOG.md

@@ -50,6 +50,8 @@
   [1277](https://github.com/nextcloud/cookbook/pull/1277)
 - Prepare the GitHub action scripts to be compatible with the upcoming version split in version 0.10.0
   [#1285](https://github.com/nextcloud/cookbook/pull/1285) @christianlupus
+- Add logging to diagnose bugs in production
+  [#1283](https://github.com/nextcloud/cookbook/pull/1283) @MarcelRobitaille
 
 ### Documentation
 - Fix bad writing

docs/dev/frontend/logging.md

@@ -0,0 +1,21 @@
+# Debugging in production through logging
+
+Sometimes, it is necessary to debug problems in production
+where it is not possible to use a debugger or other developer tools to find the
+source of the problem.
+For example, if a user reports an issue that cannot be reproduced locally,
+you can instruct them to enable logging to narrow down the source of the issue.
+
+To enable logging, a user only has to run the following before loading the app/refreshing the page:
+```js
+localStorage.setItem('COOKBOOK_LOGGING_ENABLED', 'true')
+```
+
+This will automatically be reset after 30 minutes so verbose logging is not enabled permanently for the user.
+
+The log level is also configurable. For example:
+```js
+localStorage.setItem('COOKBOOK_LOGGING_LEVEL', 'debug')
+```
+
+The documentation for the logging library used is available [here](https://www.npmjs.com/package/vuejs-logger).

docs/dev/index.md

@@ -18,6 +18,7 @@ If you want to **help contributing**, please see the [page about contributing](c
 
 - [Webpack `BundleAnalyzer` Plugin](frontend/webpack-bundle-analyzer)
 - [Hot reload capability for faster frontend development](frontend/hot-reload)
+- [Debugging in production through logging](frontend/logging)
 
 ## Backend
 

package.json

@@ -45,6 +45,7 @@
     "vue-modal-dialogs": "3.0.0",
     "vue-router": "^3.1.6",
     "vue-showdown": "^2.4.1",
+    "vuejs-logger": "1.5.5",
     "vuex": "^3.1.3"
   },
   "devDependencies": {

src/components/AppIndex.vue

@@ -38,6 +38,7 @@ export default {
         },
     },
     mounted() {
+        this.$log.info("AppIndex mounted")
         this.loadAll()
     },
     methods: {

src/components/AppMain.vue

@@ -50,6 +50,7 @@ export default {
         */
     },
     mounted() {
+        this.$log.info("AppMain mounted")
         subscribe("navigation-toggled", this.updateAppNavigationOpen)
     },
     unmounted() {

src/components/AppNavi.vue

@@ -149,6 +149,7 @@ export default {
     },
     computed: {
         totalRecipeCount() {
+            this.$log.debug("Calling totalRecipeCount")
             let total = this.uncatRecipes
             for (let i = 0; i < this.categories.length; i++) {
                 total += this.categories[i].recipeCount
@@ -168,11 +169,13 @@ export default {
         // Register a method hook for navigation refreshing
         refreshRequired(newVal, oldVal) {
             if (newVal !== oldVal && newVal === true) {
+                this.$log.debug("Calling getCategories from refreshRequired")
                 this.getCategories()
             }
         },
     },
     mounted() {
+        this.$log.info("AppNavi mounted")
         this.getCategories()
     },
     methods: {
@@ -303,6 +306,7 @@ export default {
          * Fetch and display recipe categories
          */
         async getCategories() {
+            this.$log.debug("Calling getCategories")
             const $this = this
             this.loading.categories = true
             try {
@@ -369,6 +373,7 @@ export default {
          * Reindex all recipes
          */
         reindex() {
+            this.$log.debug("Calling reindex")
             const $this = this
             if (this.scanningLibrary) {
                 // No repeat clicks until we're done
@@ -387,6 +392,7 @@ export default {
                         // This refreshes the current router view in case items in it changed during reindex
                         $this.$router.go()
                     } else {
+                        this.$log.debug("Calling getCategories from reindex")
                         $this.getCategories()
                     }
                 })

src/components/RecipeEdit.vue

@@ -395,6 +395,7 @@ export default {
         },
     },
     mounted() {
+        this.$log.info("RecipeEdit mounted")
         const $this = this
 
         // Store the initial recipe configuration for possible later use

src/components/RecipeView.vue

@@ -522,6 +522,7 @@ export default {
         },
     },
     mounted() {
+        this.$log.info("RecipeView mounted")
         this.setup()
         // Register data load method hook for access from the controls components
         this.$root.$off("reloadRecipeView")

src/js/logging.js

@@ -0,0 +1,68 @@
+// TODO: Switch to vuejs3-logger when we switch to Vue 3
+import VueLogger from "vuejs-logger"
+import moment from "@nextcloud/moment"
+
+const DEFAULT_LOG_LEVEL = "info"
+// How many minutes the logging configuration is valid for
+const EXPIRY_MINUTES = 30
+// localStorage keys
+const KEY_ENABLED = "COOKBOOK_LOGGING_ENABLED"
+const KEY_EXPIRY = "COOKBOOK_LOGGING_EXPIRY"
+const KEY_LOG_LEVEL = "COOKBOOK_LOGGING_LEVEL"
+
+// Check if the logging configuration in local storage has expired
+//
+// Since the expiry entry is added by us after the first run where
+// the enabled entry is detected, this only checks if it has been EXPIRY_MINUTES
+// since the first run, not EXPIRY_MINUTES since the user added the entry
+// This is a reasonable comprimise to simplify what the user has to do to enable
+// logging. We don't want them to have to setup the expiry as well
+const isExpired = (timestamp) => {
+    if (timestamp === null) {
+        return false
+    }
+
+    return moment().isAfter(parseInt(timestamp, 10))
+}
+
+const isEnabled = () => {
+    const DEFAULT = false
+    const userValue = localStorage.getItem(KEY_ENABLED)
+    const expiry = localStorage.getItem(KEY_EXPIRY)
+
+    // Detect the first load after the user has enabled logging
+    // Set the expiry so the logging isn't enabled forever
+    if (userValue !== null && expiry === null) {
+        localStorage.setItem(
+            KEY_EXPIRY,
+            moment().add(EXPIRY_MINUTES, "m").valueOf()
+        )
+    }
+
+    if (isExpired(expiry)) {
+        localStorage.removeItem(KEY_ENABLED)
+        localStorage.removeItem(KEY_EXPIRY)
+
+        return DEFAULT
+    }
+
+    // Local storage converts everything to string
+    // Use JSON.parse to transform "false" -> false
+    return JSON.parse(userValue) ?? DEFAULT
+}
+
+export default function setupLogging(Vue) {
+    const logLevel = localStorage.getItem(KEY_LOG_LEVEL) ?? DEFAULT_LOG_LEVEL
+
+    Vue.use(VueLogger, {
+        isEnabled: isEnabled(),
+        logLevel,
+        stringifyArguments: false,
+        showLogLevel: true,
+        showMethodName: true,
+        separator: "|",
+        showConsoleColors: true,
+    })
+
+    Vue.$log.info(`Setting up logging with log level ${logLevel}`)
+}

src/main.js

@@ -13,6 +13,7 @@ import Vue from "vue"
 import * as ModalDialogs from "vue-modal-dialogs"
 
 import helpers from "cookbook/js/helper"
+import setupLogging from "cookbook/js/logging"
 
 import router from "./router"
 import store from "./store"
@@ -52,10 +53,13 @@ Vue.use(VueShowdown, {
 // https://github.com/rlemaigre/vue3-promise-dialog
 Vue.use(ModalDialogs)
 
+setupLogging(Vue)
+
 // Pass translation engine to Vue
 Vue.prototype.t = window.t
 
 // Start the app once document is done loading
+Vue.$log.info("Main is done. Creating App.")
 const App = Vue.extend(AppMain)
 new App({
     store,