Added tracing logging, removed some unhelpful python level logging messages

Former-commit-id: 68610be7c21c24dc9c354fc0162bed4dd3438606

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"

bindings/codemp_client.cpython-38-darwin.so.REMOVED.git-id

@@ -1 +1 @@
-cbf3777125b44718cba5f2e67dcbe9a01700840b
+28b1d0465b66af6afb0266207d139e48c95173fd

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`"

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:

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,

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<CodempError> for PyCodempError {
     fn from(err: CodempError) -> Self {
@@ -39,6 +41,33 @@ impl From<PyCodempError> for PyErr {
         }
     }
 }
+
+#[derive(Debug, Clone)]
+struct LoggerProducer(mpsc::Sender<String>);
+
+impl std::io::Write for LoggerProducer {
+    fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
+        // 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<Mutex<mpsc::Receiver<String>>>);
+
+#[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<Py<PyClient>> {
     Ok(Py::new(py, PyClient::default())?)
 }
 
+#[pyfunction]
+fn init_logger(py: Python<'_>, debug: Option<bool>) -> PyResult<Py<PyLogger>> {
+    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<RwLock<Option<CodempClient>>>);
 
@@ -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::<PyClient>()?;
     m.add_class::<PyWorkspace>()?;
     m.add_class::<PyCursorController>()?;
     m.add_class::<PyBufferController>()?;
+    m.add_class::<PyLogger>()?;
 
     m.add_class::<PyId>()?;
     m.add_class::<PyCursorEvent>()?;

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):