From a302180a1995911457b9898be0f94a171cf2c946 Mon Sep 17 00:00:00 2001 From: Camillo Schenone Date: Sat, 2 Mar 2024 15:28:39 +0100 Subject: [PATCH] Added tracing logging, removed some unhelpful python level logging messages Former-commit-id: 68610be7c21c24dc9c354fc0162bed4dd3438606 --- Cargo.toml | 2 + ...client.cpython-38-darwin.so.REMOVED.git-id | 2 +- plugin.py | 26 ++++---- src/TaskManager.py | 4 +- src/codemp_client.py | 46 +++++++------- src/lib.rs | 62 ++++++++++++++++++- src/utils.py | 4 +- 7 files changed, 103 insertions(+), 43 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 2446650..236a5e1 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -14,6 +14,8 @@ pyo3 = { version = "0.20", features = ["extension-module"] } pyo3-asyncio = { version = "0.20", features = ["tokio-runtime"] } serde = { version = "1.0.196", features = ["derive"] } tokio = "1.29.1" +tracing = "0.1.40" +tracing-subscriber = "0.3.18" [build-dependencies] pyo3-build-config = "0.19.2" diff --git a/bindings/codemp_client.cpython-38-darwin.so.REMOVED.git-id b/bindings/codemp_client.cpython-38-darwin.so.REMOVED.git-id index 1ac0841..f096870 100644 --- a/bindings/codemp_client.cpython-38-darwin.so.REMOVED.git-id +++ b/bindings/codemp_client.cpython-38-darwin.so.REMOVED.git-id @@ -1 +1 @@ -cbf3777125b44718cba5f2e67dcbe9a01700840b \ No newline at end of file +28b1d0465b66af6afb0266207d139e48c95173fd \ No newline at end of file diff --git a/plugin.py b/plugin.py index 60c34dc..73e7e4a 100644 --- a/plugin.py +++ b/plugin.py @@ -2,6 +2,7 @@ import sublime import sublime_plugin from Codemp.src.codemp_client import VirtualClient +from Codemp.src.codemp_client import CodempLogger from Codemp.src.TaskManager import rt from Codemp.src.utils import status_log from Codemp.src.utils import safe_listener_detach @@ -9,6 +10,7 @@ from Codemp.src.utils import get_contents from Codemp.src.utils import populate_view from Codemp.src.utils import get_view_from_local_path import Codemp.src.globals as g +from Codemp.bindings.codemp_client import init_logger CLIENT = None TEXT_LISTENER = None @@ -25,6 +27,9 @@ def plugin_loaded(): CLIENT = VirtualClient(disconnect_client) TEXT_LISTENER = CodempClientTextChangeListener() + logger = CodempLogger(init_logger(True)) + CLIENT.tm.dispatch(logger.spawn_logger(), "codemp-logger") + status_log("plugin loaded") @@ -43,7 +48,6 @@ def plugin_unloaded(): global CLIENT # releasing the runtime, runs the disconnect callback defined when acquiring the event loop. CLIENT.tm.release(False) - status_log("plugin unloaded") # Listeners @@ -60,9 +64,6 @@ class EventListener(sublime_plugin.EventListener): for wsid in s[g.CODEMP_WINDOW_WORKSPACES]: ws = CLIENT[wsid] if ws is not None: - status_log( - f"current active: {CLIENT.active_workspace.id}, ws = {ws.id}" - ) if ws.id == CLIENT.active_workspace.id: CLIENT.active_workspace = None CLIENT.tm.stop(f"{g.CURCTL_TASK_PREFIX}-{ws.id}") @@ -87,23 +88,18 @@ class CodempClientViewEventListener(sublime_plugin.ViewEventListener): if vbuff is not None: CLIENT.send_cursor(vbuff) - # We only edit on one view at a time, therefore we only need one TextChangeListener - # Each time we focus a view to write on it, we first attach the listener to that buffer. - # When we defocus, we detach it. def on_activated(self): - global TEXT_LISTENER - # sublime has no proper way to check if a view gained or lost input focus outside of this # callback (i know right?), so we have to manually keep track of which view has the focus g.ACTIVE_CODEMP_VIEW = self.view.id() - print("view {} activated".format(self.view.id())) + # print("view {} activated".format(self.view.id())) + global TEXT_LISTENER TEXT_LISTENER.attach(self.view.buffer()) def on_deactivated(self): - global TEXT_LISTENER - g.ACTIVE_CODEMP_VIEW = None - print("view {} deactivated".format(self.view.id())) + # print("view {} deactivated".format(self.view.id())) + global TEXT_LISTENER safe_listener_detach(TEXT_LISTENER) def on_pre_close(self): @@ -193,7 +189,7 @@ class CodempJoinCommand(sublime_plugin.WindowCommand): class CodempJoinWorkspaceCommand(sublime_plugin.WindowCommand): def run(self, workspace_id): global CLIENT - rt.dispatch(CLIENT.join_workspace(workspace_id)) + rt.dispatch(CLIENT.join_workspace(workspace_id, "sublime2")) def input_description(self): return "Join specific workspace" @@ -208,7 +204,7 @@ class CodempJoinWorkspaceCommand(sublime_plugin.WindowCommand): class CodempJoinBufferCommand(sublime_plugin.WindowCommand): def run(self, buffer_id): global CLIENT - if CLIENT.active_workspace is not None: + if CLIENT.active_workspace is None: sublime.error_message( "You haven't joined any worksapce yet. \ use `Codemp: Join Workspace` or `Codemp: Join`" diff --git a/src/TaskManager.py b/src/TaskManager.py index f5b4714..c888f5b 100644 --- a/src/TaskManager.py +++ b/src/TaskManager.py @@ -56,9 +56,7 @@ class TaskManager: def stop(self, name): t = self.get_task(name) if t is not None: - rt.sync( - self._stop(t) - ) # awaiting the task blocks until it actually is finished. + rt.sync(self._stop(t)) def stop_all(self): for task in self.tasks: diff --git a/src/codemp_client.py b/src/codemp_client.py index d6c71f9..d7141a3 100644 --- a/src/codemp_client.py +++ b/src/codemp_client.py @@ -15,6 +15,26 @@ from Codemp.src.utils import status_log, rowcol_to_region from Codemp.src.TaskManager import TaskManager +class CodempLogger: + def __init__(self, handle): + self.handle = handle + + async def message(self): + return await self.handle.message() + + async def spawn_logger(self): + status_log("spinning up the logger...") + try: + while msg := await self.handle.message(): + print(msg) + except asyncio.CancelledError: + status_log("stopping logger") + raise + except Exception as e: + status_log(f"logger crashed unexpectedly:\n{e}") + raise + + # This class is used as an abstraction between the local buffers (sublime side) and the # remote buffers (codemp side), to handle the syncronicity. # This class is mainly manipulated by a VirtualWorkspace, that manages its buffers @@ -133,7 +153,6 @@ class VirtualWorkspace: async def attach(self, id: str): if id is None: - status_log("can't attach if buffer does not exist, aborting.") return await self.handle.fetch_buffers() @@ -172,10 +191,8 @@ class VirtualClient: return self.workspaces.get(key) def make_active(self, ws: VirtualWorkspace): - # TODO: Logic to deal with swapping to and from workspaces, - # what happens to the cursor tasks etc.. if self.active_workspace is not None: - self.tm.stop_and_pop(f"{g.CURCTL_TASK_PREFIX}-{self.active_workspace.id}") + self.tm.stop(f"{g.CURCTL_TASK_PREFIX}-{self.active_workspace.id}") self.active_workspace = ws self.spawn_cursor_manager(ws) @@ -193,26 +210,20 @@ class VirtualClient: status_log(f"Connected to '{server_host}' with user id: {id}") async def join_workspace( - self, workspace_id: str, user="sublime", password="***REMOVED***" + self, workspace_id: str, user="sublime2", password="***REMOVED***" ) -> VirtualWorkspace: try: status_log(f"Logging into workspace: '{workspace_id}'") await self.handle.login(user, password, workspace_id) except Exception as e: - status_log(f"Failed to login to workspace '{workspace_id}'.\nerror: {e}") - sublime.error_message( - f"Failed to login to workspace '{workspace_id}'.\nerror: {e}" - ) + status_log(f"Failed to login to workspace '{workspace_id}'.\nerror: {e}", True) return try: status_log(f"Joining workspace: '{workspace_id}'") workspace_handle = await self.handle.join_workspace(workspace_id) except Exception as e: - status_log(f"Could not join workspace '{workspace_id}'.\nerror: {e}") - sublime.error_message( - f"Could not join workspace '{workspace_id}'.\nerror: {e}" - ) + status_log(f"Could not join workspace '{workspace_id}'.\nerror: {e}", True) return vws = VirtualWorkspace(self, workspace_id, workspace_handle) @@ -229,10 +240,6 @@ class VirtualClient: vbuff = vws.get_by_remote(cursor_event.buffer) if vbuff is None: - status_log( - f"Received a cursor event for an unknown \ - or inactive buffer: {cursor_event.buffer}" - ) continue reg = rowcol_to_region( @@ -264,7 +271,7 @@ class VirtualClient: def send_cursor(self, vbuff: VirtualBuffer): # TODO: only the last placed cursor/selection. - status_log(f"sending cursor position in workspace: {vbuff.workspace.id}") + # status_log(f"sending cursor position in workspace: {vbuff.workspace.id}") region = vbuff.view.sel()[0] start = vbuff.view.rowcol(region.begin()) # only counts UTF8 chars end = vbuff.view.rowcol(region.end()) @@ -283,9 +290,6 @@ class VirtualClient: # We are not listening on it. Otherwise, interrupt the listening # to avoid echoing back the change just received. if vb.view.id() == g.ACTIVE_CODEMP_VIEW: - status_log( - "received a text change with view active, stopping the echo." - ) vb.view.settings()[g.CODEMP_IGNORE_NEXT_TEXT_CHANGE] = True # we need to go through a sublime text command, since the method, diff --git a/src/lib.rs b/src/lib.rs index 886bbe6..16133c5 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -1,7 +1,9 @@ use codemp::proto::common::Identity; use pyo3::types::PyList; use std::{format, sync::Arc}; -use tokio::sync::RwLock; +use tokio::sync::{mpsc, Mutex, RwLock}; +use tracing; +use tracing_subscriber; use codemp::prelude::*; use codemp::{errors::Error as CodempError, proto::files::BufferNode}; @@ -12,7 +14,7 @@ use pyo3::{ types::{PyString, PyType}, }; -// ERRORS ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ +// ERRORS And LOGGING ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ struct PyCodempError(CodempError); impl From for PyCodempError { fn from(err: CodempError) -> Self { @@ -39,6 +41,33 @@ impl From for PyErr { } } } + +#[derive(Debug, Clone)] +struct LoggerProducer(mpsc::Sender); + +impl std::io::Write for LoggerProducer { + fn write(&mut self, buf: &[u8]) -> std::io::Result { + // TODO this is a LOSSY logger!! + let _ = self.0.try_send(String::from_utf8_lossy(buf).to_string()); // ignore: logger disconnected or with full buffer + Ok(buf.len()) + } + + fn flush(&mut self) -> std::io::Result<()> { + Ok(()) + } +} + +#[pyclass] +struct PyLogger(Arc>>); + +#[pymethods] +impl PyLogger { + fn message<'a>(&'a self, py: Python<'a>) -> PyResult<&'a PyAny> { + let rc = self.0.clone(); + + pyo3_asyncio::tokio::future_into_py(py, async move { Ok(rc.lock().await.recv().await) }) + } +} // ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ // Workflow: @@ -57,6 +86,33 @@ fn codemp_init<'a>(py: Python<'a>) -> PyResult> { Ok(Py::new(py, PyClient::default())?) } +#[pyfunction] +fn init_logger(py: Python<'_>, debug: Option) -> PyResult> { + let (tx, rx) = mpsc::channel(256); + let level = if debug.unwrap_or(false) { + tracing::Level::DEBUG + } else { + tracing::Level::INFO + }; + let format = tracing_subscriber::fmt::format() + .without_time() + .with_level(true) + .with_target(true) + .with_thread_ids(false) + .with_thread_names(false) + .with_file(false) + .with_line_number(false) + .with_source_location(false) + .compact(); + tracing_subscriber::fmt() + .with_ansi(false) + .event_format(format) + .with_max_level(level) + .with_writer(std::sync::Mutex::new(LoggerProducer(tx))) + .init(); + Ok(Py::new(py, PyLogger(Arc::new(Mutex::new(rx))))?) +} + #[pyclass] struct PyClient(Arc>>); @@ -477,10 +533,12 @@ impl PyTextChange { #[pymodule] fn codemp_client(_py: Python, m: &PyModule) -> PyResult<()> { m.add_function(wrap_pyfunction!(codemp_init, m)?)?; + m.add_function(wrap_pyfunction!(init_logger, m)?)?; m.add_class::()?; m.add_class::()?; m.add_class::()?; m.add_class::()?; + m.add_class::()?; m.add_class::()?; m.add_class::()?; diff --git a/src/utils.py b/src/utils.py index d6d5f53..f26a449 100644 --- a/src/utils.py +++ b/src/utils.py @@ -2,9 +2,11 @@ import sublime import sublime_plugin -def status_log(msg): +def status_log(msg, popup=False): sublime.status_message("[codemp] {}".format(msg)) print("[codemp] {}".format(msg)) + if popup: + sublime.error_message(msg) def rowcol_to_region(view, start, end):