ref: add debug logging

index.js

@@ -13,6 +13,7 @@ global.APP = global.APP || {};
 global.ARGS = global.ARGS || {};
 global.EVENTS = global.EVENTS || new Events();
 
+// Check display environment variable
 if (!process.env.DISPLAY) {
   console.error(`\n$DISPLAY variable not set to run the GUI application, are you connected via SSH?\n`);
   console.error(`If you have installed the service use:`);
@@ -22,6 +23,18 @@ if (!process.env.DISPLAY) {
   process.exit(1);
 }
 
+// Delete electron log file
+const elog = path.join(app.getPath("logs"), "electron.log");
+try {
+  if (fs.existsSync(elog)) {
+    fs.unlinkSync(elog);
+  }
+  console.debug = () => {};
+} catch (error) {
+  console.error("Failed to delete electron log file:", error.message);
+}
+app.commandLine.appendSwitch("log-file", elog);
+
 /**
  * This promise resolves when the app has finished initializing,
  * allowing to safely create browser windows and perform other
@@ -38,11 +51,18 @@ app.whenReady().then(async () => {
     args.mqtt_password = "*".repeat((args.mqtt_password || "").length);
   }
   console.info(`Arguments: ${JSON.stringify(args, null, 2)}`);
+  process.stdout.write("\n");
 
   // Chained init functions
-  const chained = [webview.init, hardware.init, integration.init];
+  const chained = [
-  for (const init of chained) {
+    ["webview.js", webview.init],
+    ["hardware.js", hardware.init],
+    ["integration.js", integration.init],
+  ];
+  for (const [name, init] of chained) {
+    console.debug(`${name}: init()`);
     if (!(await init())) {
+      console.debug(`${name}: init() --> aborted`);
       break;
     }
   }
@@ -154,11 +174,18 @@ const initLog = async () => {
       fs.unlinkSync(APP.log);
     }
   } catch (error) {
-    console.error("Failed to delete log file:", error.message);
+    console.error("Failed to delete main log file:", error.message);
   }
 
-  // Overwrite console log
+  // Set log level and path
-  APP.logs = [];
+  const level = "enable_logging" in ARGS ? "silly" : "app_debug" in ARGS ? "debug" : "verbose";
+  log.transports.file.level = level;
+  log.transports.console.level = level;
+  log.transports.file.resolvePathFn = () => {
+    return APP.log;
+  };
+
+  // Catch unhandled errors
   log.errorHandler.startCatching({
     showDialog: false,
     onError({ error }) {
@@ -166,6 +193,9 @@ const initLog = async () => {
       app.exit(1);
     },
   });
+
+  // Emit console log
+  APP.logs = [];
   log.hooks.push((message, transport, type) => {
     const text = message.data.join(" ");
     if (!text.startsWith("(node:") && type === "console") {
@@ -181,10 +211,10 @@ const initLog = async () => {
     }
     return message;
   });
-  log.transports.file.resolvePathFn = () => {
+
-    return APP.log;
+  // Overwrite console log
-  };
   Object.assign(console, log.functions);
+  console.silly("Welcome To The Jungle!");
 
   return true;
 };

js/hardware.js

@@ -86,22 +86,25 @@ const init = async () => {
   // Show hardware infos
   process.stdout.write("\n");
   const unsupported = "unsupported";
-  console.info(`Battery Level [${HARDWARE.battery.level.path || unsupported}]:`, `${getBatteryLevel() || unsupported}`);
   console.info(
-    `Display Status [${HARDWARE.display.status.path || unsupported}]:`,
+    `Battery Level [${HARDWARE.support.batteryLevel ? HARDWARE.battery.level.path : unsupported}]:`,
-    `${getDisplayStatus() || unsupported} (${HARDWARE.display.status.command || unsupported})`,
+    HARDWARE.support.batteryLevel ? getBatteryLevel() : unsupported,
   );
   console.info(
-    `Display Brightness [${HARDWARE.display.brightness.path || unsupported}]:`,
+    `Display Status [${HARDWARE.support.displayStatus ? HARDWARE.display.status.path : unsupported}]:`,
-    `${getDisplayBrightness() || unsupported}`,
+    HARDWARE.support.displayStatus ? `${getDisplayStatus()} (${HARDWARE.display.status.command})` : unsupported,
+  );
+  console.info(
+    `Display Brightness [${HARDWARE.support.displayBrightness ? HARDWARE.display.brightness.path : unsupported}]:`,
+    HARDWARE.support.displayBrightness ? getDisplayBrightness() : unsupported,
   );
   console.info(
     `Audio Volume [${HARDWARE.support.audioVolume ? HARDWARE.audio.device : unsupported}]:`,
-    `${getAudioVolume() || unsupported}`,
+    HARDWARE.support.audioVolume ? getAudioVolume() : unsupported,
   );
   console.info(
-    `Keyboard Visibility [${HARDWARE.support.keyboardVisibility ? "squeekboard" : unsupported}]:`,
+    `Keyboard Visibility [${HARDWARE.support.keyboardVisibility ? "dbus://sm/puri/OSK0" : unsupported}]:`,
-    `${getKeyboardVisibility() || unsupported}`,
+    HARDWARE.support.keyboardVisibility ? `${getKeyboardVisibility()} (squeekboard)` : unsupported,
   );
   process.stdout.write("\n");
 
@@ -155,8 +158,8 @@ const update = async () => {
   if (HARDWARE.support.displayStatus) {
     const status = (await fsp.readFile(`${HARDWARE.display.status.path}/dpms`, "utf8")).trim();
     if (status !== HARDWARE.display.status.value) {
-      console.info("Update Display Status:", getDisplayStatus());
       HARDWARE.display.status.value = status;
+      console.info("Update Display Status:", getDisplayStatus());
       EVENTS.emit("updateDisplay");
     }
   }
@@ -165,8 +168,8 @@ const update = async () => {
   if (HARDWARE.support.displayBrightness) {
     const brightness = (await fsp.readFile(`${HARDWARE.display.brightness.path}/brightness`, "utf8")).trim();
     if (brightness !== HARDWARE.display.brightness.value) {
-      console.info("Update Display Brightness:", getDisplayBrightness());
       HARDWARE.display.brightness.value = brightness;
+      console.info("Update Display Brightness:", getDisplayBrightness());
       EVENTS.emit("updateDisplay");
     }
   }
@@ -241,7 +244,7 @@ const checkSupport = () => {
   return {
     batteryLevel: !!battery.path,
     displayStatus: !!status.path && !!status.command,
-    displayBrightness: sudo && !!brightness.path && !!brightness.max,
+    displayBrightness: sudo && !!status.command && !!brightness.path && !!brightness.max,
     keyboardVisibility: keyboard,
     audioVolume: !!audio,
     sudoRights: sudo,
@@ -831,10 +834,11 @@ const commandExists = (name) => {
  */
 const execSyncCommand = (cmd, args) => {
   try {
+    console.debug(`hardware.js: execSyncCommand(${[cmd, ...args].join(" ")})`);
     const output = cpr.execSync([cmd, ...args].join(" "), { encoding: "utf8" });
     return output.trim().replace(/\0/g, "");
   } catch (error) {
-    console.error(`Execute Sync: '${[cmd, ...args].join(" ")}' --> ${error.message}`);
+    console.error(`Execute Sync: '${[cmd, ...args].join(" ")}' --> ${error.message}`.trim());
   }
   return null;
 };
@@ -848,6 +852,7 @@ const execSyncCommand = (cmd, args) => {
  * @returns {Object} The spawned process object.
  */
 const execAsyncCommand = (cmd, args, callback = null) => {
+  console.debug(`hardware.js: execAsyncCommand(${[cmd, ...args].join(" ")})`);
   let errorOutput = "";
   let successOutput = "";
   let proc = cpr.spawn(cmd, args);
@@ -883,6 +888,7 @@ const execAsyncCommand = (cmd, args, callback = null) => {
  * @returns {Object} The spawned process object.
  */
 const execScriptCommand = (cmd, args, callback = null) => {
+  console.debug(`hardware.js: execScriptCommand(${[cmd, ...args].join(" ")})`);
   let progress = 1;
   let proc = cpr.spawn(cmd, args);
   if (typeof callback === "function") callback(progress, null);
@@ -932,6 +938,7 @@ const execScriptCommand = (cmd, args, callback = null) => {
  * @returns {Object} The spawned process object.
  */
 const commandMonitor = (cmd, args, callback) => {
+  console.debug(`hardware.js: commandMonitor(${[cmd, ...args].join(" ")})`);
   const proc = cpr.spawn(cmd, args);
   proc.stdout.on("data", (data) => {
     if (data) {
@@ -958,6 +965,7 @@ const commandMonitor = (cmd, args, callback) => {
 const dbusMonitor = (path, callback) => {
   const cmd = "dbus-monitor";
   const args = [`interface='org.freedesktop.DBus.Properties',member='PropertiesChanged',path='${path}'`];
+  console.debug(`hardware.js: dbusMonitor(${[cmd, ...args].join(" ")})`);
   const proc = cpr.spawn(cmd, args);
   proc.stdout.on("data", (data) => {
     try {
@@ -1006,6 +1014,7 @@ const dbusCall = (path, method, values, callback = null) => {
   const dest = `${iface} ${path} ${iface}.${method} ${values.join(" ")}`;
   const args = ["--print-reply", "--type=method_call", `--dest=${dest}`];
   try {
+    console.debug(`hardware.js: dbusCall(${[cmd, ...args].join(" ")})`);
     const output = cpr.execSync([cmd, ...args].join(" ").trim(), { encoding: "utf8" });
     if (typeof callback === "function") callback(output.trim().replace(/\0/g, ""), null);
   } catch (error) {

js/integration.js

@@ -153,6 +153,7 @@ const update = async () => {
   if (!INTEGRATION.initialized || APP.exiting) {
     return;
   }
+  console.debug("integration.js: update()");
 
   // Update client sensors
   updatePageNumber();
@@ -180,6 +181,7 @@ const removeConfig = (type, config) => {
   }
   const path = config.unique_id.replace(`${INTEGRATION.node}_`, "");
   const root = `${INTEGRATION.discovery}/${type}/${INTEGRATION.node}/${path}/config`;
+  console.debug(`integration.js: removeConfig(${path})`);
   return INTEGRATION.client.publish(root, JSON.stringify({}), { qos: 1, retain: true });
 };
 
@@ -196,6 +198,7 @@ const publishConfig = (type, config) => {
   }
   const path = config.unique_id.replace(`${INTEGRATION.node}_`, "");
   const root = `${INTEGRATION.discovery}/${type}/${INTEGRATION.node}/${path}/config`;
+  console.debug(`integration.js: publishConfig(${path})`);
   return INTEGRATION.client.publish(root, JSON.stringify(config), { qos: 1, retain: true });
 };
 

js/webview.js

@@ -75,20 +75,11 @@ const init = async () => {
     toggle: () => {
       nativeTheme.themeSource = nativeTheme.shouldUseDarkColors ? "light" : "dark";
     },
-    register: () => {
+    handler: (callback) => {
-      nativeTheme.on("updated", () => {
+      nativeTheme.on("updated", callback);
-        const theme = WEBVIEW.theme.get();
-        WEBVIEW.statusTheme = theme;
-        WEBVIEW.widgetTheme = theme;
-        WEBVIEW.navigationTheme = theme;
-        if (WEBVIEW.initialized) {
-          resizeView();
-        }
-        EVENTS.emit("updateTheme");
-      });
     },
   };
-  WEBVIEW.theme.register();
+  WEBVIEW.theme.handler(updateTheme);
   WEBVIEW.theme.set(theme);
 
   // Init global root window
@@ -190,6 +181,7 @@ const update = async () => {
   if (!WEBVIEW.initialized || APP.exiting) {
     return;
   }
+  console.debug("webview.js: update()");
 
   // Update window status
   updateStatus();
@@ -204,6 +196,28 @@ const update = async () => {
   integration.update();
 };
 
+/**
+ * Updates the application theme.
+ */
+const updateTheme = () => {
+  const previous = WEBVIEW.statusTheme;
+  const theme = WEBVIEW.theme.get();
+
+  // Set controls theme
+  if (previous !== theme) {
+    console.info("Update Application Theme:", theme);
+  }
+  WEBVIEW.statusTheme = theme;
+  WEBVIEW.widgetTheme = theme;
+  WEBVIEW.navigationTheme = theme;
+
+  // Update controls theme
+  if (WEBVIEW.initialized) {
+    resizeView();
+  }
+  EVENTS.emit("updateTheme");
+};
+
 /**
  * Updates the active view.
  */
@@ -511,7 +525,8 @@ const resizeView = () => {
   const widget = { width: 60, height: 200 };
 
   // Update view size
-  WEBVIEW.views.forEach((view) => {
+  WEBVIEW.views.forEach((view, i) => {
+    console.debug(`webview.js: resizeView(${i})`);
     view.setBounds({
       x: 0,
       y: status.height,
@@ -577,6 +592,8 @@ const resizeView = () => {
  * Register window events and handler.
  */
 const windowEvents = async () => {
+  console.debug("webview.js: windowEvents()");
+
   // Handle window resize events
   WEBVIEW.window.on("ready-to-show", resizeView);
   WEBVIEW.window.on("resize", resizeView);
@@ -686,6 +703,7 @@ const widgetEvents = async () => {
   if (!WEBVIEW.widgetEnabled) {
     return;
   }
+  console.debug("webview.js: widgetEvents()");
 
   // Handle widget focus events
   WEBVIEW.widget.webContents.on("focus", () => {
@@ -704,6 +722,7 @@ const widgetEvents = async () => {
       theme: WEBVIEW.widgetTheme,
     });
     WEBVIEW.tracker.widget.focused = true;
+    console.debug("webview.js: widgetEvents(widget-focus)");
   });
 
   // Handle widget blur events
@@ -722,10 +741,12 @@ const widgetEvents = async () => {
       theme: "hidden",
     });
     WEBVIEW.tracker.widget.focused = false;
+    console.debug("webview.js: widgetEvents(widget-blur)");
   });
 
   // Handle widget button click events
   ipcMain.on("button-click", (e, button) => {
+    console.debug(`webview.js: widgetEvents(button-click-${button.id})`);
     WEBVIEW.tracker.pointer.time = new Date();
     switch (button.id) {
       case "theme":
@@ -748,9 +769,11 @@ const statusEvents = async () => {
   if (!WEBVIEW.statusEnabled) {
     return;
   }
+  console.debug("webview.js: statusEvents()");
 
   // Handle status button click events
   ipcMain.on("button-click", (e, button) => {
+    console.debug(`webview.js: statusEvents(button-click-${button.id})`);
     WEBVIEW.tracker.pointer.time = new Date();
     switch (button.id) {
       case "fullscreen":
@@ -790,10 +813,12 @@ const navigationEvents = async () => {
   if (!WEBVIEW.navigationEnabled) {
     return;
   }
+  console.debug("webview.js: navigationEvents()");
 
   // Handle input blur events
   let selected = false;
   ipcMain.on("input-blur", (e, input) => {
+    console.debug(`webview.js: navigationEvents(input-blur-${input.id})`);
     switch (input.id) {
       case "url":
         if (selected) {
@@ -809,6 +834,7 @@ const navigationEvents = async () => {
 
   // Handle input focus events
   ipcMain.on("input-focus", (e, input) => {
+    console.debug(`webview.js: navigationEvents(input-focus-${input.id})`);
     WEBVIEW.tracker.pointer.time = new Date();
     switch (input.id) {
       case "url":
@@ -826,6 +852,8 @@ const navigationEvents = async () => {
 
   // Handle input enter events
   ipcMain.on("input-enter", (e, input) => {
+    console.debug(`webview.js: navigationEvents(input-enter-${input.id})`);
+    WEBVIEW.tracker.pointer.time = new Date();
     switch (input.id) {
       case "url":
         let url = input.text.trim();
@@ -842,6 +870,7 @@ const navigationEvents = async () => {
 
   // Handle navigation button click events
   ipcMain.on("button-click", (e, button) => {
+    console.debug(`webview.js: navigationEvents(button-click-${button.id})`);
     WEBVIEW.tracker.pointer.time = new Date();
     switch (button.id) {
       case "home":
@@ -878,6 +907,8 @@ const navigationEvents = async () => {
 const viewEvents = async () => {
   const ready = [];
   WEBVIEW.views.forEach((view, i) => {
+    console.debug(`webview.js: viewEvents(${i})`);
+
     // Enable webview touch emulation
     view.webContents.debugger.attach("1.1");
     view.webContents.debugger.sendCommand("Emulation.setEmitTouchEventsForMouse", {
@@ -893,6 +924,7 @@ const viewEvents = async () => {
 
     // Update webview layout
     view.webContents.on("dom-ready", () => {
+      console.debug(`webview.js: viewEvents(${i},dom-ready)`);
       view.webContents.insertCSS("::-webkit-scrollbar { display: none; }");
       if (ready.length < WEBVIEW.views.length) {
         view.webContents.setZoomFactor(WEBVIEW.viewZoom);
@@ -902,6 +934,7 @@ const viewEvents = async () => {
 
     // Webview fully loaded
     view.webContents.on("did-finish-load", () => {
+      console.debug(`webview.js: viewEvents(${i},did-finish-load)`);
       if (WEBVIEW.viewActive === 0 && ready.length === WEBVIEW.views.length) {
         nextView();
       }
@@ -915,6 +948,7 @@ const viewEvents = async () => {
     // Webview not loaded
     view.webContents.on("did-fail-load", (e, code, text, url, mainframe) => {
       if (mainframe) {
+        console.debug(`webview.js: viewEvents(${i},did-fail-load)`);
         if (WEBVIEW.viewActive === 0 && ready.length === WEBVIEW.views.length) {
           nextView();
         }
@@ -932,10 +966,12 @@ const viewEvents = async () => {
     // Webview url changed
     view.webContents.on("did-navigate-in-page", (e, url, mainframe) => {
       if (mainframe) {
+        console.debug(`webview.js: viewEvents(${i},did-navigate-in-page)`);
         updateView();
       }
     });
     view.webContents.on("did-navigate", () => {
+      console.debug(`webview.js: viewEvents(${i},did-navigate)`);
       updateView();
     });
 
@@ -944,17 +980,23 @@ const viewEvents = async () => {
       const now = new Date();
       const then = WEBVIEW.tracker.pointer.time;
       const delta = (now - then) / 1000;
+
+      // Check mouse event type
       switch (mouse.type) {
         case "mouseMove":
-          const posNew = { x: mouse.globalX, y: mouse.globalY };
+          const posNew = { x: Math.round(mouse.globalX), y: Math.round(mouse.globalY) };
           if (posNew.x < 0 || posNew.y < 0) {
             break;
           }
-          // Update last active on pointer position change
+          console.debug(`webview.js: viewEvents(${i},${mouse.type}-${posNew.x}-${posNew.y})`);
+
+          // Update tracker pointer time and position
           const posOld = WEBVIEW.tracker.pointer.position;
           if (posOld.x !== posNew.x || posOld.y !== posNew.y) {
             WEBVIEW.tracker.pointer.time = now;
             WEBVIEW.tracker.pointer.position = posNew;
+
+            // Update last active on pointer position change
             if (delta > 30) {
               console.info("Update Last Active");
               integration.update();
@@ -962,15 +1004,18 @@ const viewEvents = async () => {
           }
           break;
         case "mouseDown":
+          console.debug(`webview.js: viewEvents(${i},${mouse.type}-${mouse.button})`);
           switch (mouse.button) {
             case "left":
+              const off = WEBVIEW.tracker.display.off > WEBVIEW.tracker.display.on;
+              console.debug(`webview.js: viewEvents(${i},display-${off ? "off" : "on"})`);
+
               // Ignore touch event if display was off
-              if (WEBVIEW.tracker.display.off > WEBVIEW.tracker.display.on) {
+              if (off) {
                 console.verbose("Display Touch Event: Ignored");
                 e.preventDefault();
-              }
+
                 // Turn display on if it was off
-              if (hardware.getDisplayStatus() === "OFF") {
                 hardware.setDisplayStatus("ON");
               }
               break;
@@ -991,6 +1036,8 @@ const viewEvents = async () => {
  * Register app events and handler.
  */
 const appEvents = async () => {
+  console.debug("webview.js: appEvents()");
+
   // Handle global events
   EVENTS.on("reloadView", reloadView);
   EVENTS.on("updateView", updateView);
@@ -1026,6 +1073,16 @@ const appEvents = async () => {
     WEBVIEW.window.focus();
   });
 
+  // Handle crash events
+  app.on("render-process-gone", (e, wc, details) => {
+    const content = wc.getURL() || "Unknown";
+    console.error(`Render Process ${details.reason} (code ${details.exitCode}): ${content}`);
+  });
+  app.on("child-process-gone", (e, details) => {
+    const name = details.name || details.serviceName || "Unknown";
+    console.error(`${details.type} Process ${details.reason} (code ${details.exitCode}): ${name}`);
+  });
+
   // Handle exit events
   app.on("before-quit", () => {
     APP.exiting = true;