diff --git a/matrix_appservice_kakaotalk/config.py b/matrix_appservice_kakaotalk/config.py index 54d1ec7..a6afc00 100644 --- a/matrix_appservice_kakaotalk/config.py +++ b/matrix_appservice_kakaotalk/config.py @@ -117,7 +117,6 @@ class Config(BaseBridgeConfig): else: copy("rpc.connection.host") copy("rpc.connection.port") - copy("rpc.logging_keys") def _get_permissions(self, key: str) -> tuple[bool, bool, bool, str]: level = self["bridge.permissions"].get(key, "") diff --git a/matrix_appservice_kakaotalk/example-config.yaml b/matrix_appservice_kakaotalk/example-config.yaml index e8938d2..b7b8c30 100644 --- a/matrix_appservice_kakaotalk/example-config.yaml +++ b/matrix_appservice_kakaotalk/example-config.yaml @@ -252,11 +252,6 @@ rpc: # Only for type: tcp host: localhost port: 29392 - # Command arguments to print in logs. Optional. - # TODO Support nested arguments, like channel_props.ktid - logging_keys: - - mxid - #- channel_props # Python logging configuration. # diff --git a/matrix_appservice_kakaotalk/rpc/rpc.py b/matrix_appservice_kakaotalk/rpc/rpc.py index c90ef7f..15912a6 100644 --- a/matrix_appservice_kakaotalk/rpc/rpc.py +++ b/matrix_appservice_kakaotalk/rpc/rpc.py @@ -86,7 +86,6 @@ class RPCClient: _is_connected: CancelableEvent _is_disconnected: CancelableEvent _connection_lock: asyncio.Lock - _logging_keys: list[str] def __init__(self, config: Config, register_config_key: str) -> None: self.config = config @@ -106,7 +105,6 @@ class RPCClient: self._is_disconnected = CancelableEvent(self.loop) self._is_disconnected.set() self._connection_lock = asyncio.Lock() - self._logging_keys = config["rpc.logging_keys"] async def connect(self) -> None: async with self._connection_lock: @@ -149,8 +147,7 @@ class RPCClient: self._read_task = self.loop.create_task(self._try_read_loop()) await self._raw_request("register", peer_id=self.config["appservice.address"], - register_config=self.config[self.register_config_key], - logging_keys=self._logging_keys) + register_config=self.config[self.register_config_key]) self._is_connected.set() self._is_disconnected.clear() @@ -250,6 +247,7 @@ class RPCClient: self.log.debug(f"Nobody waiting for response to {req_id}") return if command == "response": + self.log.debug("Received response %d", req_id) waiter.set_result(req.get("response")) elif command == "error": waiter.set_exception(RPCError(req.get("error", line))) @@ -305,10 +303,7 @@ class RPCClient: req_id = self._next_req_id future = self._response_waiters[req_id] = self.loop.create_future() req = {"id": req_id, "command": command, **data} - self.log.debug("Request %d: %s", req_id, - ', '.join( - [command] + - [f"{k}: {data[k]}" for k in self._logging_keys if k in data])) + self.log.debug("Request %d: %s", req_id, command) assert self._writer is not None self._writer.write(json.dumps(req).encode("utf-8")) self._writer.write(b"\n") diff --git a/node/README.md b/node/README.md index 260aaa4..9419caf 100644 --- a/node/README.md +++ b/node/README.md @@ -3,5 +3,8 @@ If `type` is `unix`, `path` is the path where to create the socket, and `force` If `type` is `tcp`, `port` and `host` are the host/port where to listen. -### Register timeout +### Register timeout config `register_timeout` is the amount of time (in milliseconds) that a connecting peer must send a "register" command after initiating a connection. + +### Logging config +`logging_keys` specifies which properties of RPC request & response objects to print in logs. Optional. diff --git a/node/example-config-docker.json b/node/example-config-docker.json index 1fb93f1..082c767 100644 --- a/node/example-config-docker.json +++ b/node/example-config-docker.json @@ -3,5 +3,10 @@ "type": "unix", "path": "/data/rpc.sock", "force": true + }, + "register_timeout": 3000, + "logging_keys": { + "request": ["mxid"], + "response": ["status"] } } diff --git a/node/example-config.json b/node/example-config.json index 90a1de0..bd4f589 100644 --- a/node/example-config.json +++ b/node/example-config.json @@ -4,5 +4,9 @@ "path": "/var/run/matrix-appservice-kakaotalk/rpc.sock", "force": false }, - "register_timeout": 3000 + "register_timeout": 3000, + "logging_keys": { + "request": ["mxid"], + "response": ["status"] + } } diff --git a/node/src/client.js b/node/src/client.js index 4a7fbac..332cf80 100644 --- a/node/src/client.js +++ b/node/src/client.js @@ -425,6 +425,9 @@ export default class PeerClient { */ constructor(manager, socket, connID) { this.manager = manager + this.registerTimeout = manager.registerTimeout + this.loggingKeys = manager.loggingKeys + this.socket = socket this.connID = connID @@ -433,8 +436,6 @@ export default class PeerClient { this.maxCommandID = 0 this.peerID = "" this.deviceName = "KakaoTalk Bridge" - /** @type {[string]} */ - this.loggingKeys = [] /** @type {Map} */ this.userClients = new Map() } @@ -465,10 +466,10 @@ export default class PeerClient { setTimeout(() => { if (!this.peerID && !this.stopped) { - this.log(`Didn't receive register request within ${this.manager.registerTimeout/1000} seconds, terminating`) + this.log(`Didn't receive register request within ${this.registerTimeout/1000} seconds, terminating`) this.stop("Register request timeout") } - }, this.manager.registerTimeout) + }, this.registerTimeout) } async stop(error = null) { @@ -1194,12 +1195,10 @@ export default class PeerClient { * @param {string} req.peer_id * @param {Object} req.register_config * @param {string} req.register_config.device_name - * @param {?[string]} req.logging_keys */ handleRegister = async (req) => { this.peerID = req.peer_id this.deviceName = req.register_config.device_name || this.deviceName - this.loggingKeys = req.logging_keys || this.loggingKeys this.log(`Registered socket ${this.connID} -> ${this.peerID}`) if (this.manager.clients.has(this.peerID)) { const oldClient = this.manager.clients.get(this.peerID) @@ -1230,12 +1229,7 @@ export default class PeerClient { this.log("Ignoring old request", req.id) return } - this.log( - `Request ${req.id}:`, - [req.command].concat( - this.loggingKeys.filter(k => k in req).map(k => `${k}: ${JSON.stringify(req[k], this.#writeReplacer)}`)) - .join(', ') - ) + this.log(`Request ${req.id}:`, this.#logObj(req, req.command, this.loggingKeys.request)) this.maxCommandID = req.id let handler if (!this.peerID) { @@ -1306,17 +1300,40 @@ export default class PeerClient { resp.command = "error" if (err instanceof ProtocolError) { resp.error = err.message + this.error(`Response ${resp.id}: ${err.message}`) } else { resp.error = err.toString() - this.log(`Error handling request ${resp.id} ${err.stack}`) + this.error(`Response ${resp.id}: ${err.stack}`) } } } - // TODO Check if session is broken. If it is, close the PeerClient + if (resp.response) { + const success = resp.response.success !== false + const logger = (success ? this.log : this.error).bind(this) + logger( + `Response ${resp.id}:`, + this.#logObj( + resp.response, + success ? "success" : "failure", + this.loggingKeys.response + ) + ) + } await this.write(resp) } - #writeReplacer = function(key, value) { + /** + * @param {object} obj + * @param {string} desc + * @param {[string]} keys + */ + #logObj(obj, desc, keys) { + return [desc].concat( + keys.filter(key => key in obj).map(key => `${key}: ${JSON.stringify(obj[key], this.#writeReplacer)}`) + ).join(', ') + } + + #writeReplacer(key, value) { if (value instanceof Long) { return value.toString() } else { @@ -1324,7 +1341,7 @@ export default class PeerClient { } } - #readReviver = function(key, value) { + #readReviver(key, value) { if (value instanceof Object) { // TODO Use a type map if there will be many possible types if (value.__type__ == "Long") { diff --git a/node/src/clientmanager.js b/node/src/clientmanager.js index 3a0d94a..adf6794 100644 --- a/node/src/clientmanager.js +++ b/node/src/clientmanager.js @@ -20,11 +20,33 @@ import path from "path" import PeerClient from "./client.js" import { promisify } from "./util.js" +/** + * @typedef {object} ListenConfig + * @property {string} type + * @property {string} path + * @property {boolean} force + */ + +/** + * @typedef {object} LoggingKeys + * @property {[string]} request + * @property {[string]} response + */ + export default class ClientManager { - constructor(listenConfig, registerTimeout) { + /** + * @param {ListenConfig} listenConfig + * @param {number} registerTimeout + * @param {?LoggingKeys} loggingKeys + */ + constructor(listenConfig, registerTimeout, loggingKeys) { + if (!listenConfig) { + throw new Error("Listen config missing") + } this.listenConfig = listenConfig this.registerTimeout = registerTimeout || 3000 + this.loggingKeys = loggingKeys || {request: [], response: []} this.server = net.createServer(this.acceptConnection) this.connections = [] this.clients = new Map() @@ -43,7 +65,7 @@ export default class ClientManager { } else { const connID = this.connIDSequence++ this.connections[connID] = sock - new PeerClient(this, sock, connID).start() + new PeerClient(this, sock, connID, this.loggingKeys).start() } } diff --git a/node/src/main.js b/node/src/main.js index daa9f68..7a7798a 100644 --- a/node/src/main.js +++ b/node/src/main.js @@ -32,7 +32,11 @@ const configPath = args["--config"] || "config.json" console.log("[Main] Reading config from", configPath) const config = JSON.parse(fs.readFileSync(configPath).toString()) -const manager = new ClientManager(config.listen, config.register_timeout) +const manager = new ClientManager( + config.listen, + config.register_timeout, + config.logging_keys +) function stop() { manager.stop().then(() => {