wip logging

packages/node-mimimi/Cargo.toml

@@ -11,6 +11,7 @@ crate-type = ["cdylib"]
 napi = { version = "2.16.10", default-features = false, features = ["napi9", "async"] }
 napi-derive = "2.16.12"
 tuta-sdk = { path = "../../tuta-sdk/rust/sdk", version = "0.1.0" }
+log = "0.4.22"
 
 [build-dependencies]
 napi-build = "2.1.3"

packages/node-mimimi/src/console.rs

@@ -0,0 +1,166 @@
+use napi::bindgen_prelude::*;
+use napi::{Env, JsFunction, JsObject, JsUndefined, Task};
+
+/// todo: plumb through SDK's log messages? it's currently using simple_logger when not compiled
+/// todo: for ios or android.
+
+pub fn setup_logging(env: Env) -> Result<Console> {
+    let (tx, rx) = std::sync::mpsc::channel::<LogMessage>();
+    let logger = Logger { rx: Some(rx) };
+    let Ok(_async_task) = env.spawn(logger) else {
+        return Err(Error::from_reason("failed to spawn logger"));
+    };
+
+    let logger_thread_id = std::thread::current().id();
+    let console = Console::new(tx);
+    let panic_console = console.clone();
+    std::panic::set_hook(Box::new(move |panic_info| {
+        if logger_thread_id == std::thread::current().id() {
+            // logger is (probably) running on the currently panicking thread,
+            // so we can't use it to log to JS. this at least shows up in stderr.
+            eprintln!("PANIC MAIN {}", panic_info.to_string().as_str());
+            eprintln!("MAIN PANIC {}", std::backtrace::Backtrace::force_capture().to_string().as_str());
+        } else {
+            panic_console.error("PANIC", format!("thread {:?} {}", std::thread::current().name(), panic_info.to_string().as_str()).as_str());
+            panic_console.error("PANIC", std::backtrace::Backtrace::force_capture().to_string().as_str());
+        }
+    }));
+
+    Ok(console)
+}
+
+/// A way for the rust code to log messages to the main applications log files
+/// without having to deal with obtaining a reference to console each time.
+#[derive(Clone)]
+pub struct Console {
+    tx: std::sync::mpsc::Sender<LogMessage>,
+}
+
+impl Console {
+    pub fn new(tx: std::sync::mpsc::Sender<LogMessage>) -> Self {
+        Self { tx }
+    }
+    pub fn log(&self, tag: &str, message: &str) {
+        // todo: if the logger dies before us, print message to stdout instead and panic?
+        let _ = self.tx.send(LogMessage {
+            level: LogLevel::Log,
+            tag: tag.into(),
+            message: message.into(),
+        });
+    }
+    pub fn warn(&self, tag: &str, message: &str) {
+        let _ = self.tx.send(LogMessage {
+            level: LogLevel::Warn,
+            tag: tag.into(),
+            message: message.into(),
+        });
+    }
+
+    pub fn error(&self, tag: &str, message: &str) {
+        let _ = self.tx.send(LogMessage {
+            level: LogLevel::Error,
+            tag: tag.into(),
+            message: message.into(),
+        });
+    }
+}
+
+/// The part of the logging setup that receives log messages from the rust log
+/// {@link struct Console} and forwards them to the node environment to log.
+struct Logger {
+    /// This is an option because we need to take it from the old instance before
+    /// rescheduling the listen job with a new one.
+    rx: Option<std::sync::mpsc::Receiver<LogMessage>>,
+}
+
+impl Logger {
+    fn execute_log(&self, env: Env, log_message: LogMessage) {
+        let globals = env.get_global()
+            .expect("no globals in env");
+        let console: JsObject = globals.get_named_property("console")
+            .expect("console property not found");
+
+        let formatted_message = format!("[{} {}] {}", log_message.marker(), log_message.tag, log_message.message);
+        let js_string: napi::JsString = env.create_string_from_std(formatted_message)
+            .expect("could not create string");
+
+        let js_error: JsFunction = console.get_named_property(log_message.method())
+            .expect("logging fn not found");
+        js_error.call(None, &[js_string])
+            .expect("logging failed");
+    }
+}
+
+impl Task for Logger {
+    type Output = LogMessage;
+    type JsValue = JsUndefined;
+
+    /// runs on the libuv thread pool.
+    fn compute(&mut self) -> Result<Self::Output> {
+        if let Some(rx) = &self.rx {
+            Ok(rx.recv().unwrap_or_else(|_| LogMessage {
+                level: LogLevel::Finish,
+                tag: "Logger".to_string(),
+                message: "channel closed, logger finished".to_string(),
+            }))
+        } else {
+            // should not happen - each Logger instance listens for exactly one message and then
+            // gets dropped and reincarnated.
+            Ok(LogMessage {
+                level: LogLevel::Error,
+                tag: "Logger".to_string(),
+                message: "rx not available, already moved".to_string(),
+            })
+        }
+    }
+
+    fn resolve(&mut self, env: Env, output: Self::Output) -> Result<Self::JsValue> {
+        let level = output.level;
+        self.execute_log(env, output);
+        if level != LogLevel::Finish {
+            // we only have a &mut self, so can't revive ourselves directly.
+            // I guess this is reincarnation.
+            let rx = self.rx.take();
+            let _promise = env.spawn(Logger { rx });
+        }
+        Ok(env.get_undefined()?)
+    }
+}
+
+/// determines the urgency and some formatting of the log message
+#[derive(Eq, PartialEq, Copy, Clone)]
+enum LogLevel {
+    /// used if we want to log the fact that all consoles have been dropped (there will not be any more log messages)
+    Finish,
+    Log,
+    Warn,
+    Error,
+}
+
+struct LogMessage {
+    pub level: LogLevel,
+    pub message: String,
+    pub tag: String,
+}
+
+impl LogMessage {
+    /// get a prefix for labeling the log level in cases where it's
+    /// not obvious from terminal colors or similar
+    pub fn marker(&self) -> &str {
+        match self.level {
+            LogLevel::Finish | LogLevel::Log => "I",
+            LogLevel::Warn => "W",
+            LogLevel::Error => "E",
+        }
+    }
+
+    /// the name of the logging method to use for each log level.
+    /// very js-specific.
+    pub fn method(&self) -> &str {
+        match self.level {
+            LogLevel::Finish | LogLevel::Log => "log",
+            LogLevel::Warn => "warn",
+            LogLevel::Error => "error",
+        }
+    }
+}

packages/node-mimimi/src/imap/mod.rs

@@ -1,5 +1,3 @@
-use napi::bindgen_prelude::*;
-
 #[napi(object)]
 pub struct ImapImportParams {
     /// hostname of the imap server to import mail from
@@ -30,21 +28,19 @@ pub struct ImapImportConfig {
 }
 
 #[napi]
-pub struct ImapImporter {
+pub struct ImapImp {
     pub status: ImapImportStatus,
 }
 
 #[napi]
-impl ImapImporter {
-
-
+impl ImapImp {
     #[napi]
     pub async fn get_imap_import_config(&self) -> ImapImportConfig {
         todo!()
     }
 
     #[napi]
-    pub async fn continue_import(&self, imap_import_config: ImapImportConfig) -> ImapImportStatus {
+    pub async fn continue_import(&self, _imap_import_config: ImapImportConfig) -> ImapImportStatus {
         todo!()
     }
 

packages/node-mimimi/src/imap_importer.rs

@@ -0,0 +1,36 @@
+use crate::console::setup_logging;
+use crate::console::Console;
+use napi::bindgen_prelude::*;
+use std::sync::atomic::{AtomicBool, Ordering};
+use std::time::Duration;
+use std::{panic, thread};
+
+/// if set to true, an importer is already created for this instance of the addon.
+static IMPORTER_INIT: AtomicBool = AtomicBool::new(false);
+
+#[napi]
+pub struct ImapImporter {
+    console: Console,
+}
+
+const TAG: &'static str = file!();
+
+#[napi]
+impl ImapImporter {
+    /// only to be used once and only from the javascript side!
+    #[napi(factory)]
+    pub fn setup(env: Env) -> Result<Self> {
+        if !IMPORTER_INIT.swap(true, Ordering::Relaxed) {
+            let console = setup_logging(env)?;
+            Ok(ImapImporter { console })
+        } else {
+            Err(Error::from_reason("already created an importer!"))
+        }
+    }
+
+    #[napi]
+    pub fn log_that(&self, that: String) -> Result<()> {
+        self.console.log("that", &that);
+        Err(Error::from_reason("done"))
+    }
+}

packages/node-mimimi/src/lib.rs

@@ -3,43 +3,5 @@
 extern crate napi_derive;
 extern crate tutasdk;
 mod imap;
-
-use napi::bindgen_prelude::*;
-use napi::Ref;
-use std::ops::Deref;
-
-#[napi]
-pub struct SomeStruct {
-    cb: Box<dyn Fn(&str) -> i32>,
-}
-
-#[napi]
-impl SomeStruct {
-    #[napi(factory)]
-    pub fn setup_string_size(
-        env: Env,
-        #[napi(ts_arg_type = "(arg: string) => number")] js_cb: JsFunction,
-    ) -> Self {
-
-
-        // create a reference for the javascript function
-        let reference = env.create_reference(js_cb).expect("failed ref");
-        // todo! check how to keep the reference?
-        let cb = Box::new(move |msg: &str| {
-            let js_string: napi::JsString = env.create_string("four")
-                .expect("could not create string");
-            let js_fn: JsFunction = env.get_reference_value(&reference).expect("invalid ref");
-            js_fn.call(None, &[js_string])
-                .expect("call failed")
-                .coerce_to_number().expect("return is not a number")
-                .get_int32().expect("is not i32 compatible")
-        });
-
-        SomeStruct { cb }
-    }
-
-    #[napi]
-    pub fn get_string_size_of_four(&self) -> i32 {
-        (self.cb)("four")
-    }
-}
+mod console;
+mod imap_importer;

packages/tuta-imap/src/testing/jvm_singeleton.rs

@@ -4,6 +4,7 @@ use j4rs::{ClasspathEntry, JvmBuilder};
 static mut START_JVM_INVOCATION_COUNTER: i32 = 0;
 
 pub fn start_or_attach_to_jvm() -> i32 {
+    /// todo: SAFETY???
     unsafe {
         if START_JVM_INVOCATION_COUNTER == 0 {
             // create exactly one jvm and attach to it whenever we create a new IMAP test server

src/common/desktop/DesktopMain.ts

@@ -70,7 +70,9 @@ import { ExposedNativeInterface } from "../native/common/NativeInterface.js"
 import { DelayedImpls, exposeLocalDelayed } from "../api/common/WorkerProxy.js"
 import { DefaultDateProvider } from "../calendar/date/CalendarUtils.js"
 import { AlarmScheduler } from "../calendar/date/AlarmScheduler.js"
-import { SomeStruct } from "@tutao/node-mimimi"
+import { ImapImporter } from "@tutao/node-mimimi"
+
+mp()
 
 /**
  * Should be injected during build time.
@@ -85,13 +87,7 @@ dns.setDefaultResultOrder("ipv4first")
 setupAssetProtocol(electron)
 
 const TAG = "[DesktopMain]"
-const someStruct = SomeStruct.setupStringSize((s: string) => 2 * s.length)
-
-console.log(">>>>>>>>>>>>>> CODE FROM RUST!", someStruct.getStringSizeOfFour())
-
-setTimeout(() => someStruct, 3600 * 24)
 
-mp()
 type Components = {
 	readonly wm: WindowManager
 	readonly tfs: TempFs
@@ -336,6 +332,11 @@ async function startupInstance(components: Components) {
 	await onAppReady(components)
 }
 
+function testImapImporter() {
+	const importer = ImapImporter.setup()
+	setTimeout(() => importer.logThat("my!"), 5000)
+}
+
 async function onAppReady(components: Components) {
 	const { wm, keyStoreFacade, conf } = components
 	keyStoreFacade.getDeviceKey().catch(() => {
@@ -347,6 +348,7 @@ async function onAppReady(components: Components) {
 		}
 	})
 	err.init(wm)
+	testImapImporter()
 	// only create a window if there are none (may already have created one, e.g. for mailto handling)
 	// also don't show the window when we're an autolaunched tray app
 	const w = await wm.getLastFocused(!((await conf.getVar(DesktopConfigKey.runAsTrayApp)) && opts.wasAutoLaunched))