From b575dba30dbd247ff6077bfde8ebadce42f1375b Mon Sep 17 00:00:00 2001
From: Cristian Le <git@lecris.me>
Date: Fri, 30 Jul 2021 16:14:25 +0900
Subject: [PATCH 1/6] Add specific loggers

---
 puppet/package.json  |  60 ++++----
 puppet/src/api.js    |   5 +-
 puppet/src/main.js   |   9 ++
 puppet/src/puppet.js | 350 ++++++++++++++++++++++---------------------
 puppet/yarn.lock     |  10 ++
 5 files changed, 230 insertions(+), 204 deletions(-)

diff --git a/puppet/package.json b/puppet/package.json
index 04e955f..89d42cd 100644
--- a/puppet/package.json
+++ b/puppet/package.json
@@ -1,31 +1,33 @@
 {
-  "name": "matrix-puppeteer-line-chrome",
-  "version": "0.1.0",
-  "description": "Chrome/Puppeteer backend for matrix-puppeteer-line",
-  "repository": {
-    "type": "git",
-    "url": "git+https://src.miscworks.net/fair/matrix-puppeteer-line.git"
-  },
-  "engines": {
-    "node": ">=10.18.1"
-  },
-  "type": "module",
-  "main": "src/main.js",
-  "author": "Andrew Ferrazzutti <fair@miscworks.net>",
-  "license": "AGPL-3.0-or-later",
-  "homepage": "https://src.miscworks.net/fair/matrix-puppeteer-line",
-  "scripts": {
-    "start": "node ./src/main.js"
-  },
-  "dependencies": {
-    "arg": "^4.1.3",
-    "chrono-node": "^2.1.7",
-    "systemd-daemon": "^1.1.2",
-    "puppeteer": "9.1.1"
-  },
-  "devDependencies": {
-    "babel-eslint": "^10.1.0",
-    "eslint": "^7.7.0",
-    "eslint-plugin-import": "^2.22.0"
-  }
+	"name": "matrix-puppeteer-line-chrome",
+	"version": "0.1.0",
+	"description": "Chrome/Puppeteer backend for matrix-puppeteer-line",
+	"repository": {
+		"type": "git",
+		"url": "git+https://src.miscworks.net/fair/matrix-puppeteer-line.git"
+	},
+	"engines": {
+		"node": ">=10.18.1"
+	},
+	"type": "module",
+	"main": "src/main.js",
+	"author": "Andrew Ferrazzutti <fair@miscworks.net>",
+	"license": "AGPL-3.0-or-later",
+	"homepage": "https://src.miscworks.net/fair/matrix-puppeteer-line",
+	"scripts": {
+		"start": "node ./src/main.js"
+	},
+	"dependencies": {
+		"arg": "^4.1.3",
+		"chrono-node": "^2.1.7",
+		"systemd-daemon": "^1.1.2",
+		"puppeteer": "9.1.1",
+		"loglevel": "^1.7.1",
+		"loglevel-plugin-prefix": "^0.8.4"
+	},
+	"devDependencies": {
+		"babel-eslint": "^10.1.0",
+		"eslint": "^7.7.0",
+		"eslint-plugin-import": "^2.22.0"
+	}
 }
diff --git a/puppet/src/api.js b/puppet/src/api.js
index 04a6810..6d0fb2d 100644
--- a/puppet/src/api.js
+++ b/puppet/src/api.js
@@ -16,6 +16,7 @@
 import net from "net"
 import fs from "fs"
 import path from "path"
+import logger from "loglevel"
 
 import Client from "./client.js"
 import { promisify } from "./util.js"
@@ -57,12 +58,12 @@ export default class PuppetAPI {
 		} catch (err) {}
 		await promisify(cb => this.server.listen(socketPath, cb))
 		await fs.promises.chmod(socketPath, 0o700)
-		this.log("Now listening at", socketPath)
+		logger.info("Now listening at", socketPath)
 	}
 
 	async startTCP(port, host) {
 		await promisify(cb => this.server.listen(port, host, cb))
-		this.log(`Now listening at ${host || ""}:${port}`)
+		logger.info(`Now listening at ${host || ""}:${port}`)
 	}
 
 	async start() {
diff --git a/puppet/src/main.js b/puppet/src/main.js
index c262754..6e60017 100644
--- a/puppet/src/main.js
+++ b/puppet/src/main.js
@@ -16,6 +16,8 @@
 import process from "process"
 import fs from "fs"
 import sd from "systemd-daemon"
+import logger from "loglevel"
+import loggerprefix from "loglevel"
 
 import arg from "arg"
 
@@ -42,6 +44,13 @@ MessagesPuppeteer.extensionDir = config.extension_dir || MessagesPuppeteer.exten
 MessagesPuppeteer.cycleDelay = config.cycle_delay || MessagesPuppeteer.cycleDelay
 MessagesPuppeteer.useXdotool = config.use_xdotool || MessagesPuppeteer.useXdotool
 MessagesPuppeteer.jiggleDelay = config.jiggle_delay || MessagesPuppeteer.jiggleDelay
+logger.setLevel(config.logger.default_level || 3)
+logger.getLogger("Puppeteer").setLevel(config.logger.puppeteer.level || logger.getLevel())
+logger.getLogger("Puppeteer_details").setLevel(config.logger.puppeteer.details || 3)
+logger.getLogger("Puppeteer_spammer").setLevel(config.logger.puppeteer.spammer || 3)
+// Register and specify the logger format. Others will inherit
+loggerprefix.reg(logger)
+loggerprefix.apply(logger, { template: '[%n] %l:' });
 
 const api = new PuppetAPI(config.listen)
 
diff --git a/puppet/src/puppet.js b/puppet/src/puppet.js
index bf6546f..d146afd 100644
--- a/puppet/src/puppet.js
+++ b/puppet/src/puppet.js
@@ -15,13 +15,14 @@
 // along with this program.  If not, see <https://www.gnu.org/licenses/>.
 import process from "process"
 import path from "path"
-import { exec, execSync } from "child_process"
+import {exec, execSync} from "child_process"
 
 import puppeteer from "puppeteer"
 import chrono from "chrono-node"
+import logger from "loglevel"
 
 import TaskQueue from "./taskqueue.js"
-import { sleep } from "./util.js"
+import {sleep} from "./util.js"
 
 export default class MessagesPuppeteer {
 	static profileDir = "./profiles"
@@ -31,7 +32,7 @@ export default class MessagesPuppeteer {
 	static jiggleDelay = 30000
 	static devtools = false
 	static noSandbox = false
-	static viewport = { width: 960, height: 840 }
+	static viewport = {width: 960, height: 840}
 	static url = undefined
 	static extensionDir = "extension_files"
 
@@ -59,14 +60,17 @@ export default class MessagesPuppeteer {
 		this.jiggleTimerID = null
 		this.taskQueue = new TaskQueue(this.id)
 		this.client = client
-	}
-
-	log(...text) {
-		console.log(`[Puppeteer/${this.id}]`, ...text)
-	}
-
-	error(...text) {
-		console.error(`[Puppeteer/${this.id}]`, ...text)
+		// Distinct logger object with same format as previous method
+		// General logger for overall process
+		this.log = logger.getLogger(`Puppeteer/${this.id}`)
+		// Detailed logger for active run (event based)
+		this.dlog = logger.getLogger(`Puppeteer/${this.id}: Details`)
+		// Seperate logger for more spammy messages (timer based)
+		this.spammer = logger.getLogger(`Puppeteer/${this.id}: Spam`)
+		// Inherit config rules
+		this.log.setLevel(logger.getLogger("Puppeteer").getLevel())
+		this.dlog.setLevel(logger.getLogger("Puppeteer_details").getLevel())
+		this.spammer.setLevel(logger.getLogger("Puppeteer_spammer").getLevel())
 	}
 
 	/**
@@ -74,12 +78,12 @@ export default class MessagesPuppeteer {
 	 * This must be called before doing anything else.
 	 */
 	async start() {
-		this.log("Launching browser")
+		this.log.info("Launching browser")
 
-		const args = [
+		let args = [
 			`--disable-extensions-except=${MessagesPuppeteer.extensionDir}`,
 			`--load-extension=${MessagesPuppeteer.extensionDir}`,
-			`--window-size=${MessagesPuppeteer.viewport.width},${MessagesPuppeteer.viewport.height+120}`,
+			`--window-size=${MessagesPuppeteer.viewport.width},${MessagesPuppeteer.viewport.height + 120}`,
 		]
 		if (MessagesPuppeteer.noSandbox) {
 			args = args.concat(`--no-sandbox`)
@@ -94,7 +98,7 @@ export default class MessagesPuppeteer {
 			devtools: MessagesPuppeteer.devtools,
 			timeout: 0,
 		})
-		this.log("Opening new tab")
+		this.log.info("Opening new tab")
 		const pages = await this.browser.pages()
 		if (pages.length > 0) {
 			this.page = pages[0]
@@ -103,29 +107,29 @@ export default class MessagesPuppeteer {
 		}
 
 		{
-			this.log("Finding extension UUID")
+			this.log.info("Finding extension UUID")
 			await this.page.goto("chrome://system")
 			const selector = "#extensions-value"
 			await this.page.waitForSelector(selector, 0)
 			const lineDetails = await this.page.$eval(selector, e => e.innerText)
 			const uuid = lineDetails.match(/(.*) : LINE : version/)[1]
-			this.log(`Found extension UUID ${uuid}`)
+			this.log.info(`Found extension UUID ${uuid}`)
 			MessagesPuppeteer.url = `chrome-extension://${uuid}/index.html`
 		}
 
 		this.blankPage = await this.browser.newPage()
 		if (MessagesPuppeteer.useXdotool) {
-			this.log("Finding window ID")
+			this.log.info("Finding window ID")
 			const buffer = execSync("xdotool search 'about:blank'")
 			this.windowID = Number.parseInt(buffer)
-			this.log(`Found window ID ${this.windowID}`)
+			this.log.info(`Found window ID ${this.windowID}`)
 		}
 
-		this.log(`Opening ${MessagesPuppeteer.url}`)
+		this.log.info(`Opening ${MessagesPuppeteer.url}`)
 		await this.page.setBypassCSP(true) // Needed to load content scripts
 		await this._preparePage(true)
 
-		this.log("Exposing functions")
+		this.log.info("Exposing functions")
 		await this.page.exposeFunction("__mautrixReceiveQR", this._receiveQRChange.bind(this))
 		await this.page.exposeFunction("__mautrixSendEmailCredentials", this._sendEmailCredentials.bind(this))
 		await this.page.exposeFunction("__mautrixReceivePIN", this._receivePIN.bind(this))
@@ -145,7 +149,7 @@ export default class MessagesPuppeteer {
 		this.loginRunning = false
 		this.loginCancelled = false
 		this.taskQueue.start()
-		this.log("Startup complete")
+		this.log.info("Startup complete")
 	}
 
 	async _preparePage(navigateTo) {
@@ -155,8 +159,8 @@ export default class MessagesPuppeteer {
 		} else {
 			await this.page.reload()
 		}
-		this.log("Injecting content script")
-		await this.page.addScriptTag({ path: "./src/contentscript.js", type: "module" })
+		this.log.info("Injecting content script")
+		await this.page.addScriptTag({path: "./src/contentscript.js", type: "module"})
 	}
 
 	async _interactWithPage(promiser) {
@@ -164,7 +168,7 @@ export default class MessagesPuppeteer {
 		try {
 			await promiser()
 		} catch (e) {
-			this.error(`Error while interacting with page: ${e}`)
+			this.log.error(`Error while interacting with page: ${e}`)
 			throw e
 		} finally {
 			await this.blankPage.bringToFront()
@@ -180,7 +184,7 @@ export default class MessagesPuppeteer {
 				if (numTries && --numTries == 0) {
 					throw e
 				} else if (failMessage) {
-					this.log(failMessage)
+					this.log.error(failMessage)
 				}
 			}
 		}
@@ -211,51 +215,51 @@ export default class MessagesPuppeteer {
 		const loginContentArea = await this.page.waitForSelector("#login_content")
 
 		switch (login_type) {
-		case "qr": {
-			this.log("Running QR login")
-			const qrButton = await this.page.waitForSelector("#login_qr_btn")
-			await qrButton.click()
+			case "qr": {
+				this.dlog.info("Running QR login")
+				const qrButton = await this.page.waitForSelector("#login_qr_btn")
+				await qrButton.click()
 
-			const qrElement = await this.page.waitForSelector("#login_qrcode_area div[title]", {visible: true})
-			const currentQR = await this.page.evaluate(element => element.title, qrElement)
-			this._receiveQRChange(currentQR)
+				const qrElement = await this.page.waitForSelector("#login_qrcode_area div[title]", {visible: true})
+				const currentQR = await this.page.evaluate(element => element.title, qrElement)
+				this._receiveQRChange(currentQR)
 
-			await this.page.evaluate(
-				element => window.__mautrixController.addQRChangeObserver(element), qrElement)
-			await this.page.evaluate(
-				element => window.__mautrixController.addQRAppearObserver(element), loginContentArea)
+				await this.page.evaluate(
+					element => window.__mautrixController.addQRChangeObserver(element), qrElement)
+				await this.page.evaluate(
+					element => window.__mautrixController.addQRAppearObserver(element), loginContentArea)
 
-			break
-		}
-		case "email": {
-			this.log("Running email login")
-			if (!login_data) {
-				this._sendLoginFailure("No login credentials provided for email login")
-				return
+				break
 			}
+			case "email": {
+				this.dlog.info("Running email login")
+				if (!login_data) {
+					this._sendLoginFailure("No login credentials provided for email login")
+					return
+				}
 
-			const emailButton = await this.page.waitForSelector("#login_email_btn")
-			await emailButton.click()
+				const emailButton = await this.page.waitForSelector("#login_email_btn")
+				await emailButton.click()
 
-			await this.page.waitForSelector("#login_email_area", {visible: true})
-			this.login_email = login_data["email"]
-			this.login_password = login_data["password"]
-			await this._sendEmailCredentials()
+				await this.page.waitForSelector("#login_email_area", {visible: true})
+				this.login_email = login_data["email"]
+				this.login_password = login_data["password"]
+				await this._sendEmailCredentials()
 
-			await this.page.evaluate(
-				element => window.__mautrixController.addEmailAppearObserver(element), loginContentArea)
+				await this.page.evaluate(
+					element => window.__mautrixController.addEmailAppearObserver(element), loginContentArea)
 
-			break
-		}
-		default:
-			this._sendLoginFailure(`Invalid login type: ${login_type}`)
-			return
+				break
+			}
+			default:
+				this._sendLoginFailure(`Invalid login type: ${login_type}`)
+				return
 		}
 
 		await this.page.evaluate(
 			element => window.__mautrixController.addPINAppearObserver(element), loginContentArea)
 
-		this.log("Waiting for login response")
+		this.dlog.info("Waiting for login response")
 		let doneWaiting = false
 		let loginSuccess = false
 		const cancelableResolve = (promiseFn) => {
@@ -289,7 +293,7 @@ export default class MessagesPuppeteer {
 		].map(promiseFn => cancelableResolve(promiseFn)))
 
 		if (!this.loginCancelled) {
-			this.log("Removing observers")
+			this.dlog.info("Removing observers")
 			// TODO __mautrixController is undefined when cancelling, why?
 			await this.page.evaluate(ownID => window.__mautrixController.setOwnID(ownID), this.ownID)
 			await this.page.evaluate(() => window.__mautrixController.removeQRChangeObserver())
@@ -309,28 +313,28 @@ export default class MessagesPuppeteer {
 		}
 
 		this._sendLoginSuccess()
-		this.log("Waiting for sync")
+		this.dlog.info("Waiting for sync")
 		try {
 			await this.page.waitForFunction(
 				messageSyncElement => {
 					const text = messageSyncElement.innerText
 					return text.startsWith("Syncing messages...")
 						&& (text.endsWith("100%") || text.endsWith("NaN%"))
-						// TODO Sometimes it gets stuck at 99%...??
+					// TODO Sometimes it gets stuck at 99%...??
 				},
 				{timeout: 10000}, // Assume 10 seconds is long enough
 				messageSyncElement)
 		} catch (err) {
 			//this._sendLoginFailure(`Failed to sync: ${err}`)
-			this.log("LINE's sync took too long, assume it's fine and carry on...")
+			this.dlog.warn("LINE's sync took too long, assume it's fine and carry on...")
 		} finally {
 			const syncText = await messageSyncElement.evaluate(e => e.innerText)
-			this.log(`Final sync text is: "${syncText}"`)
+			this.dlog.info(`Final sync text is: "${syncText}"`)
 		}
 
 		this.loginRunning = false
 		await this.blankPage.bringToFront()
-		this.log("Login complete")
+		this.dlog.info("Login complete")
 	}
 
 	/**
@@ -366,7 +370,7 @@ export default class MessagesPuppeteer {
 		if (this.browser) {
 			await this.browser.close()
 		}
-		this.log("Everything stopped")
+		this.log.info("Everything stopped")
 	}
 
 	/**
@@ -494,7 +498,7 @@ export default class MessagesPuppeteer {
 	 * @return {Promise<{id: number}>} - The ID of the sent message.
 	 */
 	async sendMessage(chatID, text) {
-		return { id: await this.taskQueue.push(() => this._sendMessageUnsafe(chatID, text)) }
+		return {id: await this.taskQueue.push(() => this._sendMessageUnsafe(chatID, text))}
 	}
 
 	/**
@@ -512,14 +516,14 @@ export default class MessagesPuppeteer {
 		for (const [chatID, messageID] of Object.entries(msgIDs)) {
 			this.mostRecentMessages.set(chatID, messageID)
 		}
-		this.log("Updated most recent message ID map:")
-		this.log(JSON.stringify(msgIDs))
+		this.dlog.info("Updated most recent message ID map:")
+		this.dlog.debug(JSON.stringify(msgIDs))
 
 		for (const [chatID, messageID] of Object.entries(ownMsgIDs)) {
 			this.mostRecentOwnMessages.set(chatID, messageID)
 		}
-		this.log("Updated most recent own message ID map:")
-		this.log(JSON.stringify(ownMsgIDs))
+		this.dlog.info("Updated most recent own message ID map:")
+		this.dlog.debug(JSON.stringify(ownMsgIDs))
 
 		this.mostRecentReceipts.clear()
 		for (const [chatID, receipts] of Object.entries(rctIDs)) {
@@ -528,11 +532,11 @@ export default class MessagesPuppeteer {
 				receiptMap.set(+count, receiptID)
 			}
 		}
-		this.log("Updated most recent receipt ID map")
+		this.dlog.info("Updated most recent receipt ID map")
 		for (const [chatID, receiptMap] of this.mostRecentReceipts) {
-			this.log(`${chatID}:`)
+			this.dlog.debug(`${chatID}:`)
 			for (const [count, receiptID] of receiptMap) {
-				this.log(`Read by ${count}: ${receiptID}`)
+				this.dlog.debug(`Read by ${count}: ${receiptID}`)
 			}
 		}
 	}
@@ -552,7 +556,7 @@ export default class MessagesPuppeteer {
 	}
 
 	async sendFile(chatID, filePath) {
-		return { id: await this.taskQueue.push(() => this._sendFileUnsafe(chatID, filePath)) }
+		return {id: await this.taskQueue.push(() => this._sendFileUnsafe(chatID, filePath))}
 	}
 
 	_cycleTimerStart() {
@@ -562,7 +566,7 @@ export default class MessagesPuppeteer {
 	}
 
 	async _cycleChatUnsafe() {
-		this.log("Cycling chats")
+		this.dlog.info("Cycling chats")
 		const initialID = this.cycleTimerID
 
 		const currentChatID = await this.page.evaluate(() => window.__mautrixController.getCurrentChatID())
@@ -575,7 +579,7 @@ export default class MessagesPuppeteer {
 		// - the most recently-sent own message is not fully read
 		let chatIDToSync
 		for (let i = 0, n = chatList.length; i < n; i++) {
-			const chatListItem = chatList[(i+offset) % n]
+			const chatListItem = chatList[(i + offset) % n]
 
 			if (chatListItem.notificationCount > 0) {
 				// Chat has unread notifications, so don't view it
@@ -601,13 +605,13 @@ export default class MessagesPuppeteer {
 			}
 
 			chatIDToSync = chatListItem.id
-			this.log(`Viewing chat ${chatIDToSync} to check for new read receipts`)
+			this.dlog.debug(`Viewing chat ${chatIDToSync} to check for new read receipts`)
 			await this._syncChat(chatIDToSync)
 			break
 		}
 
 		if (!chatIDToSync) {
-			this.log("Found no chats in need of read receipt updates")
+			this.dlog.debug("Found no chats in need of read receipt updates")
 		}
 
 		if (this.cycleTimerID == initialID) {
@@ -624,27 +628,27 @@ export default class MessagesPuppeteer {
 	}
 
 	_jiggleMouse() {
-		this.log("Jiggling mouse")
+		this.spammer.info("Jiggling mouse")
 		const initialID = this.jiggleTimerID
 
 		exec(`xdotool mousemove --sync --window ${this.windowID} 0 0`, {},
-		(error, stdout, stderr) => {
-			if (error) {
-				this.log(`Error while jiggling mouse: ${error}`)
-			} else {
-				this.log("Jiggled mouse")
-			}
+			(error, stdout, stderr) => {
+				if (error) {
+					this.spammer.error(`Error while jiggling mouse: ${error}`)
+				} else {
+					this.spammer.debug("Jiggled mouse")
+				}
 
-			if (this.jiggleTimerID == initialID) {
-				this._jiggleTimerStart()
-			}
-		})
+				if (this.jiggleTimerID == initialID) {
+					this._jiggleTimerStart()
+				}
+			})
 	}
 
 	async startObserving() {
 		// TODO Highly consider syncing anything that was missed since stopObserving...
 		const chatID = await this.page.evaluate(() => window.__mautrixController.getCurrentChatID())
-		this.log(`Adding observers for ${chatID || "empty chat"}, and global timers`)
+		this.dlog.info(`Adding observers for ${chatID || "empty chat"}, and global timers`)
 		await this.page.evaluate(
 			() => window.__mautrixController.addChatListObserver())
 		if (chatID) {
@@ -662,7 +666,7 @@ export default class MessagesPuppeteer {
 	}
 
 	async stopObserving() {
-		this.log("Removing observers and timers")
+		this.dlog.info("Removing observers and timers")
 		await this.page.evaluate(
 			() => window.__mautrixController.removeChatListObserver())
 		await this.page.evaluate(
@@ -687,12 +691,12 @@ export default class MessagesPuppeteer {
 		//      Best to use this on startup when no chat is viewed.
 		let ownProfile
 		await this._interactWithPage(async () => {
-			this.log("Opening settings view")
+			this.dlog.info("Opening settings view")
 			await this.page.click("button.mdGHD01SettingBtn")
 			await this.page.waitForSelector("#context_menu li#settings", {visible: true}).then(e => e.click())
 			await this.page.waitForSelector("#settings_contents", {visible: true})
 
-			this.log("Getting own profile info")
+			this.dlog.info("Getting own profile info")
 			ownProfile = {
 				id: this.ownID,
 				name: await this.page.$eval("#settings_basic_name_input", e => e.innerText),
@@ -727,7 +731,7 @@ export default class MessagesPuppeteer {
 
 	async _switchChat(chatID, forceView = false) {
 		// TODO Allow passing in an element directly
-		this.log(`Switching to chat ${chatID}`)
+		this.dlog.info(`Switching to chat ${chatID}`)
 		let chatItem = await this.page.$(this._chatItemSelector(chatID))
 
 		let chatName
@@ -745,23 +749,23 @@ export default class MessagesPuppeteer {
 
 		if (!!chatItem && await this.page.evaluate(isCorrectChatVisible, chatName)) {
 			if (!forceView) {
-				this.log("Already viewing chat, no need to switch")
+				this.dlog.debug("Already viewing chat, no need to switch")
 			} else {
 				await this._interactWithPage(async () => {
-					this.log("Already viewing chat, but got request to view it")
+					this.dlog.debug("Already viewing chat, but got request to view it")
 					this.page.waitForTimeout(500)
 				})
 			}
 		} else {
-			this.log("Ensuring msg list observer is removed")
+			this.dlog.info("Ensuring msg list observer is removed")
 			const hadMsgListObserver = await this.page.evaluate(
 				() => window.__mautrixController.removeMsgListObserver())
-			this.log(hadMsgListObserver ? "Observer was already removed" : "Removed observer")
+			this.dlog.info(hadMsgListObserver ? "Observer was already removed" : "Removed observer")
 
 			let switchedTabs = false
 			let needRealClick = false
 			if (!chatItem) {
-				this.log(`Chat ${chatID} not in recents list`)
+				this.dlog.info(`Chat ${chatID} not in recents list`)
 
 				if (chatID.charAt(0) != "u") {
 					needRealClick = true
@@ -784,13 +788,13 @@ export default class MessagesPuppeteer {
 				// HTML of friend/group item titles ever diverge
 				chatName = await chatItem.evaluate(
 					chatID.charAt(0) == "u"
-					? element => window.__mautrixController.getFriendsListItemName(element)
-					: element => window.__mautrixController.getGroupListItemName(element))
+						? element => window.__mautrixController.getFriendsListItemName(element)
+						: element => window.__mautrixController.getGroupListItemName(element))
 			}
 
 			await this._retryUntilSuccess(3, "Clicking chat item didn't work...try again",
 				async () => {
-					this.log("Clicking chat item")
+					this.dlog.info("Clicking chat item")
 					if (!needRealClick) {
 						await chatItem.evaluate(e => e.click())
 					} else {
@@ -798,7 +802,7 @@ export default class MessagesPuppeteer {
 							await chatItem.click()
 						})
 					}
-					this.log(`Waiting for chat header title to be "${chatName}"`)
+					this.dlog.debug(`Waiting for chat header title to be "${chatName}"`)
 					await this.page.waitForFunction(
 						isCorrectChatVisible,
 						{polling: "mutation", timeout: 1000},
@@ -810,7 +814,7 @@ export default class MessagesPuppeteer {
 
 			await this._interactWithPage(async () => {
 				// Always show the chat details sidebar, as this makes life easier
-				this.log("Waiting for detail area to be auto-hidden upon entering chat")
+				this.dlog.debug("Waiting for detail area to be auto-hidden upon entering chat")
 				await this.page.waitForFunction(
 					detailArea => detailArea.childElementCount == 0,
 					{},
@@ -818,47 +822,47 @@ export default class MessagesPuppeteer {
 
 				await this._retryUntilSuccess(3, "Clicking chat header didn't work...try again",
 					async () => {
-						this.log("Clicking chat header to show detail area")
+						this.dlog.debug("Clicking chat header to show detail area")
 						await this.page.click("#_chat_header_area > .mdRGT04Link")
-						this.log("Waiting for detail area")
+						this.dlog.debug("Waiting for detail area")
 						await this.page.waitForSelector("#_chat_detail_area > .mdRGT02Info", {timeout: 1000})
 					})
 			})
 
-			this.log("Waiting for any item to appear in chat")
+			this.dlog.debug("Waiting for any item to appear in chat")
 			try {
 				await this.page.waitForSelector("#_chat_room_msg_list div", {timeout: 2000})
 
-				this.log("Waiting for chat to stabilize")
+				this.dlog.debug("Waiting for chat to stabilize")
 				await this.page.evaluate(() => window.__mautrixController.waitForMessageListStability())
 			} catch (e) {
-				this.log("No messages in chat found. Maybe no messages were ever sent yet?")
+				this.dlog.warn("No messages in chat found. Maybe no messages were ever sent yet?")
 			}
 
 			if (hadMsgListObserver) {
-				this.log("Restoring msg list observer")
+				this.dlog.debug("Restoring msg list observer")
 				await this.page.evaluate(
 					(mostRecentMessage) => window.__mautrixController.addMsgListObserver(mostRecentMessage),
 					this.mostRecentMessages.get(chatID))
 			} else {
-				this.log("Not restoring msg list observer, as there never was one")
+				this.dlog.debug("Not restoring msg list observer, as there never was one")
 			}
 		}
 	}
 
 	async _getChatInfoUnsafe(chatID, forceView) {
 		// TODO Commonize this
-		let [isDirect, isGroup, isRoom] = [false,false,false]
+		let [isDirect, isGroup, isRoom] = [false, false, false]
 		switch (chatID.charAt(0)) {
-		case "u":
-			isDirect = true
-			break
-		case "c":
-			isGroup = true
-			break
-		case "r":
-			isRoom = true
-			break
+			case "u":
+				isDirect = true
+				break
+			case "c":
+				isGroup = true
+				break
+			case "r":
+				isRoom = true
+				break
 		}
 
 		const chatListItem = await this.page.$(this._chatItemSelector(chatID))
@@ -872,7 +876,7 @@ export default class MessagesPuppeteer {
 					(element, chatID) => window.__mautrixController.parseFriendsListItem(element, chatID),
 					chatID)
 
-				this.log(`Found NEW direct chat with ${chatID}`)
+				this.dlog.info(`Found NEW direct chat with ${chatID}`)
 				return {
 					participants: [friendsListInfo],
 					id: chatID,
@@ -893,7 +897,7 @@ export default class MessagesPuppeteer {
 
 		let participants
 		if (!isDirect) {
-			this.log("Found multi-user chat, so viewing it to get participants")
+			this.dlog.info("Found multi-user chat, so viewing it to get participants")
 			// TODO This will mark the chat as "read"!
 			await this._switchChat(chatID, forceView)
 			const participantList = await this.page.$("#_chat_detail_area > .mdRGT02Info ul.mdRGT13Ul")
@@ -902,9 +906,9 @@ export default class MessagesPuppeteer {
 			participants = await participantList.evaluate(
 				element => window.__mautrixController.parseParticipantList(element))
 		} else {
-			this.log(`Found direct chat with ${chatID}`)
+			this.dlog.info(`Found direct chat with ${chatID}`)
 			if (forceView) {
-				this.log("Viewing chat on request")
+				this.dlog.info("Viewing chat on request")
 				await this._switchChat(chatID, forceView)
 			}
 			//const chatDetailArea = await this.page.waitForSelector("#_chat_detail_area > .mdRGT02Info")
@@ -916,9 +920,9 @@ export default class MessagesPuppeteer {
 			}]
 		}
 
-		this.log("Found participants:")
+		this.dlog.info("Found participants:")
 		for (const participant of participants) {
-			this.log(JSON.stringify(participant))
+			this.dlog.debug(JSON.stringify(participant))
 		}
 		return {participants, ...chatListInfo}
 	}
@@ -965,16 +969,16 @@ export default class MessagesPuppeteer {
 
 		try {
 			this._interactWithPage(async () => {
-				this.log(`About to ask for file chooser in ${chatID}`)
+				this.dlog.info(`About to ask for file chooser in ${chatID}`)
 				const [fileChooser] = await Promise.all([
 					this.page.waitForFileChooser(),
 					this.page.click("#_chat_room_plus_btn")
 				])
-				this.log(`About to upload ${filePath}`)
+				this.dlog.info(`About to upload ${filePath}`)
 				await fileChooser.accept([filePath])
 			})
 		} catch (e) {
-			this.log(`Failed to upload file to ${chatID}`)
+			this.dlog.error(`Failed to upload file to ${chatID}`)
 			return -1
 		}
 
@@ -983,16 +987,16 @@ export default class MessagesPuppeteer {
 
 	async _waitForSentMessage(chatID) {
 		try {
-			this.log("Waiting for message to be sent")
+			this.dlog.debug("Waiting for message to be sent")
 			const id = await this.page.evaluate(
 				() => window.__mautrixController.waitForOwnMessage())
-			this.log(`Successfully sent message ${id} to ${chatID}`)
+			this.dlog.debug(`Successfully sent message ${id} to ${chatID}`)
 			this.mostRecentMessages.set(chatID, id)
 			this.mostRecentOwnMessages.set(chatID, id)
 			return id
 		} catch (e) {
 			// TODO Catch if something other than a timeout
-			this.error(`Timed out sending message to ${chatID}`)
+			this.dlog.error(`Timed out sending message to ${chatID}`)
 			// TODO Figure out why e is undefined...
 			//this.error(e)
 			return -1
@@ -1006,19 +1010,19 @@ export default class MessagesPuppeteer {
 		if (this.client) {
 			for (const message of messages) {
 				this.client.sendMessage(message).catch(err =>
-					this.error("Failed to send message", message.id, "to client:", err))
+					this.dlog.error("Failed to send message", message.id, "to client:", err))
 			}
 		} else {
-			this.log("No client connected, not sending messages")
+			this.dlog.info("No client connected, not sending messages")
 		}
 	}
 
 	async _getMessagesUnsafe(chatID) {
 		// TODO Consider making a wrapper for pausing/resuming the msg list observers
-		this.log("Ensuring msg list observer is removed")
+		this.dlog.info("Ensuring msg list observer is removed")
 		const hadMsgListObserver = await this.page.evaluate(
 			() => window.__mautrixController.removeMsgListObserver())
-		this.log(hadMsgListObserver ? "Observer was already removed" : "Removed observer")
+		this.dlog.info(hadMsgListObserver ? "Observer was already removed" : "Removed observer")
 
 		// TODO Handle unloaded messages. Maybe scroll up
 		// TODO This will mark the chat as "read"!
@@ -1039,14 +1043,14 @@ export default class MessagesPuppeteer {
 		// Sync receipts seen from newly-synced messages
 		// TODO When user leaves, clear the read-by count for the old number of other participants
 		let minCountToFind = 1
-		for (let i = messages.length-1; i >= 0; i--) {
+		for (let i = messages.length - 1; i >= 0; i--) {
 			const message = messages[i]
 			if (!message.is_outgoing) {
 				continue
 			}
 			const count = message.receipt_count
 			if (count >= minCountToFind && message.id > (receiptMap.get(count) || 0)) {
-				minCountToFind = count+1
+				minCountToFind = count + 1
 				receiptMap.set(count, message.id)
 			}
 			// TODO Early exit when count == num other participants
@@ -1065,12 +1069,12 @@ export default class MessagesPuppeteer {
 
 
 		if (hadMsgListObserver) {
-			this.log("Restoring msg list observer")
+			this.dlog.info("Restoring msg list observer")
 			await this.page.evaluate(
 				mostRecentMessage => window.__mautrixController.addMsgListObserver(mostRecentMessage),
 				this.mostRecentMessages.get(chatID))
 		} else {
-			this.log("Not restoring msg list observer, as there never was one")
+			this.dlog.info("Not restoring msg list observer, as there never was one")
 		}
 
 		return {
@@ -1089,7 +1093,7 @@ export default class MessagesPuppeteer {
 			const newLastID = filteredMessages[filteredMessages.length - 1].id
 			this.mostRecentMessages.set(chatID, newLastID)
 			const range = newFirstID === newLastID ? newFirstID : `${newFirstID}-${newLastID}`
-			this.log(`Loaded ${messages.length} messages in ${chatID}, got ${filteredMessages.length} newer than ${minID} (${range})`)
+			this.dlog.info(`Loaded ${messages.length} messages in ${chatID}, got ${filteredMessages.length} newer than ${minID} (${range})`)
 			for (const message of filteredMessages) {
 				message.chat_id = chatID
 			}
@@ -1130,14 +1134,14 @@ export default class MessagesPuppeteer {
 	async _processChatListChangeUnsafe(chatListInfo) {
 		const chatID = chatListInfo.id
 		this.updatedChats.delete(chatID)
-		this.log("Processing change to", chatID)
+		this.dlog.info("Processing change to", chatID)
 		// TODO Also process name/icon changes
 
 		const prevNumNotifications = this.numChatNotifications.get(chatID) || 0
 		const diffNumNotifications = chatListInfo.notificationCount - prevNumNotifications
 
 		if (chatListInfo.notificationCount == 0 && diffNumNotifications < 0) {
-			this.log("Notifications dropped--must have read messages from another LINE client, skip")
+			this.dlog.info("Notifications dropped--must have read messages from another LINE client, skip")
 			this.numChatNotifications.set(chatID, 0)
 			return
 		}
@@ -1146,12 +1150,12 @@ export default class MessagesPuppeteer {
 			// If >1, a notification was missed. Only way to get them is to view the chat.
 			// If == 0, might be own message...or just a shuffled chat, or something else.
 			// To play it safe, just sync them. Should be no harm, as they're viewed already.
-			   diffNumNotifications != 1
+			diffNumNotifications != 1
 			// Without placeholders, some messages require visiting their chat to be synced.
 			|| !this.sendPlaceholders
 			&& (
 				// Can only use previews for DMs, because sender can't be found otherwise!
-				   chatListInfo.id.charAt(0) != 'u'
+				chatListInfo.id.charAt(0) != 'u'
 				// Sync when lastMsg is a canned message for a non-previewable message type.
 				|| chatListInfo.lastMsg.endsWith(" sent a photo.")
 				|| chatListInfo.lastMsg.endsWith(" sent a sticker.")
@@ -1181,25 +1185,25 @@ export default class MessagesPuppeteer {
 		const {messages, receipts} = await this._getMessagesUnsafe(chatID)
 
 		if (messages.length == 0) {
-			this.log("No new messages found in", chatID)
+			this.dlog.info("No new messages found in", chatID)
 		} else {
 			this._receiveMessages(chatID, messages, true)
 		}
 
 		if (receipts.length == 0) {
-			this.log("No new receipts found in", chatID)
+			this.dlog.info("No new receipts found in", chatID)
 		} else {
 			this._receiveReceiptMulti(chatID, receipts, true)
 		}
 	}
 
 	_receiveChatListChanges(changes) {
-		this.log(`Received chat list changes: ${changes.map(item => item.id)}`)
+		this.dlog.info(`Received chat list changes: ${changes.map(item => item.id)}`)
 		for (const item of changes) {
 			if (!this.updatedChats.has(item.id)) {
 				this.updatedChats.add(item.id)
 				this.taskQueue.push(() => this._processChatListChangeUnsafe(item))
-					.catch(err => this.error("Error handling chat list changes:", err))
+					.catch(err => this.dlog.error("Error handling chat list changes:", err))
 			}
 		}
 	}
@@ -1208,17 +1212,17 @@ export default class MessagesPuppeteer {
 		const receiptMap = this._getReceiptMap(chat_id)
 		const prevReceiptID = (receiptMap.get(1) || 0)
 		if (receipt_id <= prevReceiptID) {
-			this.log(`Received OUTDATED read receipt ${receipt_id} (older than ${prevReceiptID}) for chat ${chat_id}`)
+			this.dlog.info(`Received OUTDATED read receipt ${receipt_id} (older than ${prevReceiptID}) for chat ${chat_id}`)
 			return
 		}
 		receiptMap.set(1, receipt_id)
 
-		this.log(`Received read receipt ${receipt_id} (since ${prevReceiptID}) for chat ${chat_id}`)
+		this.dlog.info(`Received read receipt ${receipt_id} (since ${prevReceiptID}) for chat ${chat_id}`)
 		if (this.client) {
 			this.client.sendReceipt({chat_id: chat_id, id: receipt_id})
-				.catch(err => this.error("Error handling read receipt:", err))
+				.catch(err => this.dlog.error("Error handling read receipt:", err))
 		} else {
-			this.log("No client connected, not sending receipts")
+			this.dlog.info("No client connected, not sending receipts")
 		}
 	}
 
@@ -1236,29 +1240,29 @@ export default class MessagesPuppeteer {
 				}
 			})
 			if (receipts.length == 0) {
-				this.log(`Received ALL OUTDATED bulk read receipts for chat ${chat_id}:`, receipts)
+				this.dlog.info(`Received ALL OUTDATED bulk read receipts for chat ${chat_id}:`, receipts)
 				return
 			}
 			this._trimReceiptMap(receiptMap)
 		}
 
-		this.log(`Received bulk read receipts for chat ${chat_id}:`, receipts)
+		this.dlog.info(`Received bulk read receipts for chat ${chat_id}:`, receipts)
 		if (this.client) {
 			for (const receipt of receipts) {
 				receipt.chat_id = chat_id
 				try {
 					await this.client.sendReceipt(receipt)
-				} catch(err) {
-					this.error("Error handling read receipt:", err)
+				} catch (err) {
+					this.dlog.error("Error handling read receipt:", err)
 				}
 			}
 		} else {
-			this.log("No client connected, not sending receipts")
+			this.dlog.info("No client connected, not sending receipts")
 		}
 	}
 
 	async _sendEmailCredentials() {
-		this.log("Inputting login credentials")
+		this.dlog.info("Inputting login credentials")
 		await this._enterText(await this.page.$("#line_login_email"), this.login_email)
 		await this._enterText(await this.page.$("#line_login_pwd"), this.login_password)
 		await this.page.click("button#login_btn")
@@ -1267,51 +1271,51 @@ export default class MessagesPuppeteer {
 	_receiveQRChange(url) {
 		if (this.client) {
 			this.client.sendQRCode(url).catch(err =>
-				this.error("Failed to send new QR to client:", err))
+				this.dlog.error("Failed to send new QR to client:", err))
 		} else {
-			this.log("No client connected, not sending new QR")
+			this.dlog.warn("No client connected, not sending new QR")
 		}
 	}
 
 	_receivePIN(pin) {
 		if (this.client) {
 			this.client.sendPIN(pin).catch(err =>
-				this.error("Failed to send new PIN to client:", err))
+				this.dlog.error("Failed to send new PIN to client:", err))
 		} else {
-			this.log("No client connected, not sending new PIN")
+			this.dlog.warn("No client connected, not sending new PIN")
 		}
 	}
 
 	_sendLoginSuccess() {
-		this.error("Login success")
+		this.dlog.info("Login success")
 		if (this.client) {
 			this.client.sendLoginSuccess().catch(err =>
-				this.error("Failed to send login success to client:", err))
+				this.dlog.error("Failed to send login success to client:", err))
 		} else {
-			this.log("No client connected, not sending login success")
+			this.dlog.warn("No client connected, not sending login success")
 		}
 	}
 
 	_sendLoginFailure(reason) {
 		this.loginRunning = false
-		this.error(`Login failure: ${reason ? reason : "cancelled"}`)
+		this.dlog.error(`Login failure: ${reason ? reason : "cancelled"}`)
 		if (this.client) {
 			this.client.sendLoginFailure(reason).catch(err =>
-				this.error("Failed to send login failure to client:", err))
+				this.dlog.error("Failed to send login failure to client:", err))
 		} else {
-			this.log("No client connected, not sending login failure")
+			this.dlog.warn("No client connected, not sending login failure")
 		}
 	}
 
 	_onLoggedOut() {
-		this.log("Got logged out!")
+		this.dlog.info("Got logged out!")
 		this.stopObserving()
 		this.page.bringToFront()
 		if (this.client) {
 			this.client.sendLoggedOut().catch(err =>
-				this.error("Failed to send logout notice to client:", err))
+				this.dlog.error("Failed to send logout notice to client:", err))
 		} else {
-			this.log("No client connected, not sending logout notice")
+			this.dlog.warn("No client connected, not sending logout notice")
 		}
 	}
 }
diff --git a/puppet/yarn.lock b/puppet/yarn.lock
index 244a88d..57b3f13 100644
--- a/puppet/yarn.lock
+++ b/puppet/yarn.lock
@@ -932,6 +932,16 @@ lodash@^4.17.14, lodash@^4.17.19:
   resolved "https://registry.yarnpkg.com/lodash/-/lodash-4.17.20.tgz#b44a9b6297bcb698f1c51a3545a2b3b368d59c52"
   integrity sha512-PlhdFcillOINfeV7Ni6oF1TAEayyZBoZ8bcshTHqOYJYlrqzRK5hagpagky5o4HfCzzd1TRkXPMFq6cKk9rGmA==
 
+loglevel-plugin-prefix@^0.8.4:
+  version "0.8.4"
+  resolved "https://registry.yarnpkg.com/loglevel-plugin-prefix/-/loglevel-plugin-prefix-0.8.4.tgz#2fe0e05f1a820317d98d8c123e634c1bd84ff644"
+  integrity sha512-WpG9CcFAOjz/FtNht+QJeGpvVl/cdR6P0z6OcXSkr8wFJOsV2GRj2j10JLfjuA4aYkcKCNIEqRGCyTife9R8/g==
+
+loglevel@^1.7.1:
+  version "1.7.1"
+  resolved "https://registry.yarnpkg.com/loglevel/-/loglevel-1.7.1.tgz#005fde2f5e6e47068f935ff28573e125ef72f197"
+  integrity sha512-Hesni4s5UkWkwCGJMQGAh71PaLUmKFM60dHvq0zi/vDhhrzuk+4GgNbTXJ12YYQJn6ZKBDNIjYcuQGKudvqrIw==
+
 minimatch@^3.0.4:
   version "3.0.4"
   resolved "https://registry.yarnpkg.com/minimatch/-/minimatch-3.0.4.tgz#5166e286457f03306064be5497e8dbb0c3d32083"
-- 
2.39.5


From 4e639ee2ff917665cda97e56efd6109c87944d8b Mon Sep 17 00:00:00 2001
From: Cristian Le <git@lecris.me>
Date: Fri, 30 Jul 2021 16:54:50 +0900
Subject: [PATCH 2/6] Mistakes and nullchecks

Doesn't javascript support
`a?.b?.c`?
---
 puppet/src/main.js | 14 ++++++++------
 1 file changed, 8 insertions(+), 6 deletions(-)

diff --git a/puppet/src/main.js b/puppet/src/main.js
index 6e60017..b2d1a2d 100644
--- a/puppet/src/main.js
+++ b/puppet/src/main.js
@@ -17,7 +17,7 @@ import process from "process"
 import fs from "fs"
 import sd from "systemd-daemon"
 import logger from "loglevel"
-import loggerprefix from "loglevel"
+import loggerprefix from "loglevel-plugin-prefix"
 
 import arg from "arg"
 
@@ -44,13 +44,15 @@ MessagesPuppeteer.extensionDir = config.extension_dir || MessagesPuppeteer.exten
 MessagesPuppeteer.cycleDelay = config.cycle_delay || MessagesPuppeteer.cycleDelay
 MessagesPuppeteer.useXdotool = config.use_xdotool || MessagesPuppeteer.useXdotool
 MessagesPuppeteer.jiggleDelay = config.jiggle_delay || MessagesPuppeteer.jiggleDelay
-logger.setLevel(config.logger.default_level || 3)
-logger.getLogger("Puppeteer").setLevel(config.logger.puppeteer.level || logger.getLevel())
-logger.getLogger("Puppeteer_details").setLevel(config.logger.puppeteer.details || 3)
-logger.getLogger("Puppeteer_spammer").setLevel(config.logger.puppeteer.spammer || 3)
+let clog = config.logger
+let clogpup = clog ? clog.puppeteer : undefined
+logger.setLevel(clog ? clog.default_level || 3 : 3)
+logger.getLogger("Puppeteer").setLevel(clogpup ? clogpup.level : logger.getLevel())
+logger.getLogger("Puppeteer_details").setLevel(clogpup ? clogpup.details : 3)
+logger.getLogger("Puppeteer_spammer").setLevel(clogpup ? clogpup.spammer : 3)
 // Register and specify the logger format. Others will inherit
 loggerprefix.reg(logger)
-loggerprefix.apply(logger, { template: '[%n] %l:' });
+loggerprefix.apply(logger, {template: '[%n] %l:'});
 
 const api = new PuppetAPI(config.listen)
 
-- 
2.39.5


From 0a6609e6c97c6ac9d336955ebbae80245eaf9693 Mon Sep 17 00:00:00 2001
From: Cristian Le <git@lecris.me>
Date: Fri, 30 Jul 2021 17:02:42 +0900
Subject: [PATCH 3/6] Defaults not undefined

---
 puppet/src/main.js | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/puppet/src/main.js b/puppet/src/main.js
index b2d1a2d..80048bc 100644
--- a/puppet/src/main.js
+++ b/puppet/src/main.js
@@ -47,9 +47,9 @@ MessagesPuppeteer.jiggleDelay = config.jiggle_delay || MessagesPuppeteer.jiggleD
 let clog = config.logger
 let clogpup = clog ? clog.puppeteer : undefined
 logger.setLevel(clog ? clog.default_level || 3 : 3)
-logger.getLogger("Puppeteer").setLevel(clogpup ? clogpup.level : logger.getLevel())
-logger.getLogger("Puppeteer_details").setLevel(clogpup ? clogpup.details : 3)
-logger.getLogger("Puppeteer_spammer").setLevel(clogpup ? clogpup.spammer : 3)
+logger.getLogger("Puppeteer").setLevel(clogpup ? clogpup.level || logger.getLevel() : logger.getLevel())
+logger.getLogger("Puppeteer_details").setLevel(clogpup ? clogpup.details || 3 : 3)
+logger.getLogger("Puppeteer_spammer").setLevel(clogpup ? clogpup.spammer || 3 : 3)
 // Register and specify the logger format. Others will inherit
 loggerprefix.reg(logger)
 loggerprefix.apply(logger, {template: '[%n] %l:'});
-- 
2.39.5


From 3fdb6cc8d3c69ec7375a5095bcd7aca20c95305e Mon Sep 17 00:00:00 2001
From: Cristian Le <git@lecris.me>
Date: Fri, 30 Jul 2021 17:39:42 +0900
Subject: [PATCH 4/6] Implement logger for remaining

---
 puppet/src/api.js       | 16 +++-----
 puppet/src/client.js    | 83 ++++++++++++++++++++---------------------
 puppet/src/main.js      |  2 +
 puppet/src/taskqueue.js | 21 ++++-------
 4 files changed, 56 insertions(+), 66 deletions(-)

diff --git a/puppet/src/api.js b/puppet/src/api.js
index 6d0fb2d..d89b4a5 100644
--- a/puppet/src/api.js
+++ b/puppet/src/api.js
@@ -16,7 +16,6 @@
 import net from "net"
 import fs from "fs"
 import path from "path"
-import logger from "loglevel"
 
 import Client from "./client.js"
 import { promisify } from "./util.js"
@@ -30,10 +29,7 @@ export default class PuppetAPI {
 		this.clients = new Map()
 		this.connIDSequence = 0
 		this.stopped = false
-	}
-
-	log(...text) {
-		console.log("[API]", ...text)
+		this.log = require("loglevel").getLogger("API")
 	}
 
 	acceptConnection = sock => {
@@ -58,16 +54,16 @@ export default class PuppetAPI {
 		} catch (err) {}
 		await promisify(cb => this.server.listen(socketPath, cb))
 		await fs.promises.chmod(socketPath, 0o700)
-		logger.info("Now listening at", socketPath)
+		this.log.info("Now listening at", socketPath)
 	}
 
 	async startTCP(port, host) {
 		await promisify(cb => this.server.listen(port, host, cb))
-		logger.info(`Now listening at ${host || ""}:${port}`)
+		this.log.info(`Now listening at ${host || ""}:${port}`)
 	}
 
 	async start() {
-		this.log("Starting server")
+		this.log.info("Starting server")
 
 		if (this.listenConfig.type === "unix") {
 			await this.startUnix(this.listenConfig.path)
@@ -85,14 +81,14 @@ export default class PuppetAPI {
 			socket.end()
 			socket.destroy()
 		}
-		this.log("Stopping server")
+		this.log.info("Stopping server")
 		await promisify(cb => this.server.close(cb))
 		if (this.listenConfig.type === "unix") {
 			try {
 				await fs.promises.unlink(this.listenConfig.path)
 			} catch (err) {}
 		}
-		this.log("Stopping puppets")
+		this.log.info("Stopping puppets")
 		for (const puppet of this.puppets.values()) {
 			await puppet.stop()
 		}
diff --git a/puppet/src/client.js b/puppet/src/client.js
index 2a3b280..40fb0eb 100644
--- a/puppet/src/client.js
+++ b/puppet/src/client.js
@@ -14,7 +14,8 @@
 // You should have received a copy of the GNU Affero General Public License
 // along with this program.  If not, see <https://www.gnu.org/licenses/>.
 import MessagesPuppeteer from "./puppet.js"
-import { emitLines, promisify } from "./util.js"
+import {emitLines, promisify} from "./util.js"
+import logger from "loglevel";
 
 export default class Client {
 	/**
@@ -28,31 +29,27 @@ export default class Client {
 		this.manager = manager
 		this.socket = socket
 		this.connID = connID
-		this.userID = userID
 		this.puppet = puppet
 		this.stopped = false
 		this.notificationID = 0
 		this.maxCommandID = 0
-	}
-
-	log(...text) {
-		if (this.userID) {
-			console.log(`[API/${this.userID}/${this.connID}]`, ...text)
-		} else {
-			console.log(`[API/${this.connID}]`, ...text)
+		this.set_userID(userID)
+		if (!this.userID) {
+			this.log = require("loglevel").getLogger(`API/${this.connID}`)
+			this.log.setLevel(logger.getLogger("API").getLevel())
 		}
 	}
 
-	error(...text) {
+	set_userID(ID) {
+		this.userID = ID
 		if (this.userID) {
-			console.error(`[API/${this.userID}/${this.connID}]`, ...text)
-		} else {
-			console.error(`[API/${this.connID}]`, ...text)
+			this.log = require("loglevel").getLogger(`API/${this.userID}/${this.connID}`)
+			this.log.setLevel(logger.getLogger(`API/${this.connID}`).getLevel())
 		}
 	}
 
 	start() {
-		this.log("Received connection", this.connID)
+		this.log.info("Received connection", this.connID)
 		emitLines(this.socket)
 		this.socket.on("line", line => this.handleLine(line)
 			.catch(err => this.log("Error handling line:", err)))
@@ -60,7 +57,7 @@ export default class Client {
 
 		setTimeout(() => {
 			if (!this.userID && !this.stopped) {
-				this.log("Didn't receive register request within 3 seconds, terminating")
+				this.log.warn("Didn't receive register request within 3 seconds, terminating")
 				this.stop("Register request timeout")
 			}
 		}, 3000)
@@ -72,10 +69,10 @@ export default class Client {
 		}
 		this.stopped = true
 		try {
-			await this._write({ id: --this.notificationID, command: "quit", error })
+			await this._write({id: --this.notificationID, command: "quit", error})
 			await promisify(cb => this.socket.end(cb))
 		} catch (err) {
-			this.error("Failed to end connection:", err)
+			this.log.error("Failed to end connection:", err)
 			this.socket.destroy(err)
 		}
 	}
@@ -85,7 +82,7 @@ export default class Client {
 		if (this.userID && this.manager.clients.get(this.userID) === this) {
 			this.manager.clients.delete(this.userID)
 		}
-		this.log(`Connection closed (user: ${this.userID})`)
+		this.log.info(`Connection closed (user: ${this.userID})`)
 	}
 
 	/**
@@ -99,7 +96,7 @@ export default class Client {
 	}
 
 	sendMessage(message) {
-		this.log(`Sending message ${message.id || "with no ID"} to client`)
+		this.log.debug(`Sending message ${message.id || "with no ID"} to client`)
 		return this._write({
 			id: --this.notificationID,
 			command: "message",
@@ -109,7 +106,7 @@ export default class Client {
 	}
 
 	sendReceipt(receipt) {
-		this.log(`Sending read receipt (${receipt.count || "DM"}) of msg ${receipt.id} for chat ${receipt.chat_id}`)
+		this.log.debug(`Sending read receipt (${receipt.count || "DM"}) of msg ${receipt.id} for chat ${receipt.chat_id}`)
 		return this._write({
 			id: --this.notificationID,
 			command: "receipt",
@@ -118,7 +115,7 @@ export default class Client {
 	}
 
 	sendQRCode(url) {
-		this.log(`Sending QR ${url} to client`)
+		this.log.debug(`Sending QR ${url} to client`)
 		return this._write({
 			id: --this.notificationID,
 			command: "qr",
@@ -127,7 +124,7 @@ export default class Client {
 	}
 
 	sendPIN(pin) {
-		this.log(`Sending PIN ${pin} to client`)
+		this.log.debug(`Sending PIN ${pin} to client`)
 		return this._write({
 			id: --this.notificationID,
 			command: "pin",
@@ -136,7 +133,7 @@ export default class Client {
 	}
 
 	sendLoginSuccess() {
-		this.log("Sending login success to client")
+		this.log.debug("Sending login success to client")
 		return this._write({
 			id: --this.notificationID,
 			command: "login_success",
@@ -144,7 +141,7 @@ export default class Client {
 	}
 
 	sendLoginFailure(reason) {
-		this.log(`Sending login failure to client${reason ? `: "${reason}"` : ""}`)
+		this.log.debug(`Sending login failure to client${reason ? `: "${reason}"` : ""}`)
 		return this._write({
 			id: --this.notificationID,
 			command: "login_failure",
@@ -153,7 +150,7 @@ export default class Client {
 	}
 
 	sendLoggedOut() {
-		this.log("Sending logout notice to client")
+		this.log.debug("Sending logout notice to client")
 		return this._write({
 			id: --this.notificationID,
 			command: "logged_out",
@@ -163,7 +160,7 @@ export default class Client {
 	handleStart = async (req) => {
 		let started = false
 		if (this.puppet === null) {
-			this.log("Opening new puppeteer for", this.userID)
+			this.log.info("Opening new puppeteer for", this.userID)
 			this.puppet = new MessagesPuppeteer(this.userID, this.ownID, this.sendPlaceholders, this)
 			this.manager.puppets.set(this.userID, this.puppet)
 			await this.puppet.start(!!req.debug)
@@ -179,13 +176,13 @@ export default class Client {
 
 	handleStop = async () => {
 		if (this.puppet === null) {
-			return { stopped: false }
+			return {stopped: false}
 		}
-		this.log("Closing puppeteer for", this.userID)
+		this.log.info("Closing puppeteer for", this.userID)
 		this.manager.puppets.delete(this.userID)
 		await this.puppet.stop()
 		this.puppet = null
-		return { stopped: true }
+		return {stopped: true}
 	}
 
 	handleUnknownCommand = () => {
@@ -193,14 +190,14 @@ export default class Client {
 	}
 
 	handleRegister = async (req) => {
-		this.userID = req.user_id
+		this.set_userID(req.user_id)
 		this.ownID = req.own_id
 		this.sendPlaceholders = req.ephemeral_events
-		this.log(`Registered socket ${this.connID} -> ${this.userID}${!this.sendPlaceholders ? "" : " (with placeholder message support)"}`)
+		this.log.info(`Registered socket ${this.connID} -> ${this.userID}${!this.sendPlaceholders ? "" : " (with placeholder message support)"}`)
 		if (this.manager.clients.has(this.userID)) {
 			const oldClient = this.manager.clients.get(this.userID)
 			this.manager.clients.set(this.userID, this)
-			this.log(`Terminating previous socket ${oldClient.connID} for ${this.userID}`)
+			this.log.info(`Terminating previous socket ${oldClient.connID} for ${this.userID}`)
 			await oldClient.stop("Socket replaced by new connection")
 		} else {
 			this.manager.clients.set(this.userID, this)
@@ -209,41 +206,41 @@ export default class Client {
 		if (this.puppet) {
 			this.puppet.client = this
 		}
-		return { client_exists: this.puppet !== null }
+		return {client_exists: this.puppet !== null}
 	}
 
 	async handleLine(line) {
 		if (this.stopped) {
-			this.log("Ignoring line, client is stopped")
+			this.log.info("Ignoring line, client is stopped")
 			return
 		}
 		let req
 		try {
 			req = JSON.parse(line)
 		} catch (err) {
-			this.log("Non-JSON request:", line)
+			this.log.error("Non-JSON request:", line)
 			return
 		}
 		if (!req.command || !req.id) {
-			this.log("Invalid request:", line)
+			this.log.error("Invalid request:", line)
 			return
 		}
 		if (req.id <= this.maxCommandID) {
-			this.log("Ignoring old request", req.id)
+			this.log.warn("Ignoring old request", req.id)
 			return
 		}
 		if (req.command != "is_connected") {
-			this.log("Received request", req.id, "with command", req.command)
+			this.log.info("Received request", req.id, "with command", req.command)
 		}
 		this.maxCommandID = req.id
 		let handler
 		if (!this.userID) {
 			if (req.command !== "register") {
-				this.log("First request wasn't a register request, terminating")
+				this.log.info("First request wasn't a register request, terminating")
 				await this.stop("Invalid first request")
 				return
 			} else if (!req.user_id) {
-				this.log("Register request didn't contain user ID, terminating")
+				this.log.info("Register request didn't contain user ID, terminating")
 				await this.stop("Invalid register request")
 				return
 			}
@@ -267,17 +264,17 @@ export default class Client {
 				get_chat: req => this.puppet.getChatInfo(req.chat_id, req.force_view),
 				get_messages: req => this.puppet.getMessages(req.chat_id),
 				read_image: req => this.puppet.readImage(req.image_url),
-				is_connected: async () => ({ is_connected: !await this.puppet.isDisconnected() }),
+				is_connected: async () => ({is_connected: !await this.puppet.isDisconnected()}),
 			}[req.command] || this.handleUnknownCommand
 		}
-		const resp = { id: req.id }
+		const resp = {id: req.id}
 		try {
 			resp.command = "response"
 			resp.response = await handler(req)
 		} catch (err) {
 			resp.command = "error"
 			resp.error = err.toString()
-			this.log("Error handling request", req.id, err)
+			this.log.error("Error handling request", req.id, err)
 		}
 		await this._write(resp)
 	}
diff --git a/puppet/src/main.js b/puppet/src/main.js
index 80048bc..2c77485 100644
--- a/puppet/src/main.js
+++ b/puppet/src/main.js
@@ -50,6 +50,8 @@ logger.setLevel(clog ? clog.default_level || 3 : 3)
 logger.getLogger("Puppeteer").setLevel(clogpup ? clogpup.level || logger.getLevel() : logger.getLevel())
 logger.getLogger("Puppeteer_details").setLevel(clogpup ? clogpup.details || 3 : 3)
 logger.getLogger("Puppeteer_spammer").setLevel(clogpup ? clogpup.spammer || 3 : 3)
+logger.getLogger("TaskQueue").setLevel(clog ? clog.task_queue || 3 : 3)
+logger.getLogger("API").setLevel(clog ? clog.api || 3 : 3)
 // Register and specify the logger format. Others will inherit
 loggerprefix.reg(logger)
 loggerprefix.apply(logger, {template: '[%n] %l:'});
diff --git a/puppet/src/taskqueue.js b/puppet/src/taskqueue.js
index e3e7074..6335d2b 100644
--- a/puppet/src/taskqueue.js
+++ b/puppet/src/taskqueue.js
@@ -13,6 +13,7 @@
 //
 // You should have received a copy of the GNU Affero General Public License
 // along with this program.  If not, see <https://www.gnu.org/licenses/>.
+import logger from "loglevel"
 
 export default class TaskQueue {
 	constructor(id) {
@@ -20,21 +21,15 @@ export default class TaskQueue {
 		this._tasks = []
 		this.running = false
 		this._wakeup = null
-	}
-
-	log(...text) {
-		console.log(`[TaskQueue/${this.id}]`, ...text)
-	}
-
-	error(...text) {
-		console.error(`[TaskQueue/${this.id}]`, ...text)
+		this.log = logger.getLogger(`TaskQueue/${this.id}`)
+		this.log.setLevel(logger.getLogger("TaskQueue").getLevel())
 	}
 
 	async _run() {
-		this.log("Started processing tasks")
+		this.log.info("Started processing tasks")
 		while (this.running) {
 			if (this._tasks.length === 0) {
-				this.log("Sleeping until a new task is received")
+				this.log.debug("Sleeping until a new task is received")
 				await new Promise(resolve => this._wakeup = () => {
 					resolve()
 					this._wakeup = null
@@ -42,12 +37,12 @@ export default class TaskQueue {
 				if (!this.running) {
 					break
 				}
-				this.log("Continuing processing tasks")
+				this.log.debug("Continuing processing tasks")
 			}
 			const { task, resolve, reject } = this._tasks.shift()
 			await task().then(resolve, reject)
 		}
-		this.log("Stopped processing tasks")
+		this.log.info("Stopped processing tasks")
 	}
 
 	/**
@@ -79,7 +74,7 @@ export default class TaskQueue {
 			return
 		}
 		this.running = true
-		this._run().catch(err => this.error("Fatal error processing tasks:", err))
+		this._run().catch(err => this.log.error("Fatal error processing tasks:", err))
 	}
 
 	/**
-- 
2.39.5


From a477d10d298d42cd98038ff92129bdea70340db7 Mon Sep 17 00:00:00 2001
From: Cristian Le <git@lecris.me>
Date: Fri, 30 Jul 2021 17:45:11 +0900
Subject: [PATCH 5/6] `require` does not work?

---
 puppet/src/api.js    | 3 ++-
 puppet/src/client.js | 2 +-
 2 files changed, 3 insertions(+), 2 deletions(-)

diff --git a/puppet/src/api.js b/puppet/src/api.js
index d89b4a5..f56bf29 100644
--- a/puppet/src/api.js
+++ b/puppet/src/api.js
@@ -16,6 +16,7 @@
 import net from "net"
 import fs from "fs"
 import path from "path"
+import logger from "loglevel";
 
 import Client from "./client.js"
 import { promisify } from "./util.js"
@@ -29,7 +30,7 @@ export default class PuppetAPI {
 		this.clients = new Map()
 		this.connIDSequence = 0
 		this.stopped = false
-		this.log = require("loglevel").getLogger("API")
+		this.log = logger.getLogger("API")
 	}
 
 	acceptConnection = sock => {
diff --git a/puppet/src/client.js b/puppet/src/client.js
index 40fb0eb..9840f36 100644
--- a/puppet/src/client.js
+++ b/puppet/src/client.js
@@ -35,7 +35,7 @@ export default class Client {
 		this.maxCommandID = 0
 		this.set_userID(userID)
 		if (!this.userID) {
-			this.log = require("loglevel").getLogger(`API/${this.connID}`)
+			this.log = logger.getLogger(`API/${this.connID}`)
 			this.log.setLevel(logger.getLogger("API").getLevel())
 		}
 	}
-- 
2.39.5


From 855966e547dc8c2cd83c86a04edf9d86ca753146 Mon Sep 17 00:00:00 2001
From: Cristian Le <git@lecris.me>
Date: Fri, 30 Jul 2021 17:47:01 +0900
Subject: [PATCH 6/6] Forgot one

---
 puppet/src/client.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/puppet/src/client.js b/puppet/src/client.js
index 9840f36..626fe75 100644
--- a/puppet/src/client.js
+++ b/puppet/src/client.js
@@ -43,7 +43,7 @@ export default class Client {
 	set_userID(ID) {
 		this.userID = ID
 		if (this.userID) {
-			this.log = require("loglevel").getLogger(`API/${this.userID}/${this.connID}`)
+			this.log = logger.getLogger(`API/${this.userID}/${this.connID}`)
 			this.log.setLevel(logger.getLogger(`API/${this.connID}`).getLevel())
 		}
 	}
-- 
2.39.5