add PluginLogger, finally works in the LSP

cli/js/40_lint.js

@@ -995,26 +995,26 @@ function _dump(ctx) {
 
   // @ts-ignore dump fn
   // deno-lint-ignore no-console
-  console.log(strTable);
+  console.error(strTable);
 
   for (let i = 0; i < strByType.length; i++) {
     const v = strByType[i];
     // @ts-ignore dump fn
     // deno-lint-ignore no-console
-    if (v > 0) console.log(" > type:", i, getString(ctx.strTable, v), v);
+    if (v > 0) console.error(" > type:", i, getString(ctx.strTable, v), v);
   }
   // @ts-ignore dump fn
   // deno-lint-ignore no-console
-  console.log();
+  console.error();
   for (let i = 0; i < strByProp.length; i++) {
     const v = strByProp[i];
     // @ts-ignore dump fn
     // deno-lint-ignore no-console
-    if (v > 0) console.log(" > prop:", i, getString(ctx.strTable, v), v);
+    if (v > 0) console.error(" > prop:", i, getString(ctx.strTable, v), v);
   }
   // @ts-ignore dump fn
   // deno-lint-ignore no-console
-  console.log();
+  console.error();
 
   let offset = 0;
 
@@ -1023,14 +1023,14 @@ function _dump(ctx) {
     const name = getString(ctx.strTable, ctx.strByType[type]);
     // @ts-ignore dump fn
     // deno-lint-ignore no-console
-    console.log(`${name}, offset: ${offset}, type: ${type}`);
+    console.error(`${name}, offset: ${offset}, type: ${type}`);
     offset += 1;
 
     const parent = readU32(buf, offset);
     offset += 4;
     // @ts-ignore dump fn
     // deno-lint-ignore no-console
-    console.log(`  parent: ${parent}`);
+    console.error(`  parent: ${parent}`);
 
     const start = readU32(buf, offset);
     offset += 4;
@@ -1038,12 +1038,12 @@ function _dump(ctx) {
     offset += 4;
     // @ts-ignore dump fn
     // deno-lint-ignore no-console
-    console.log(`  range: ${start} -> ${end}`);
+    console.error(`  range: ${start} -> ${end}`);
 
     const count = buf[offset++];
     // @ts-ignore dump fn
     // deno-lint-ignore no-console
-    console.log(`  prop count: ${count}`);
+    console.error(`  prop count: ${count}`);
 
     for (let i = 0; i < count; i++) {
       const prop = buf[offset++];
@@ -1063,43 +1063,43 @@ function _dump(ctx) {
         offset += 4;
         // @ts-ignore dump fn
         // deno-lint-ignore no-console
-        console.log(`    ${name}: ${v} (${kindName}, ${prop})`);
+        console.error(`    ${name}: ${v} (${kindName}, ${prop})`);
       } else if (kind === PropFlags.RefArr) {
         const len = readU32(buf, offset);
         offset += 4;
         // @ts-ignore dump fn
         // deno-lint-ignore no-console
-        console.log(`    ${name}: Array(${len}) (${kindName}, ${prop})`);
+        console.error(`    ${name}: Array(${len}) (${kindName}, ${prop})`);
 
         for (let j = 0; j < len; j++) {
           const v = readU32(buf, offset);
           offset += 4;
           // @ts-ignore dump fn
           // deno-lint-ignore no-console
-          console.log(`      - ${v} (${prop})`);
+          console.error(`      - ${v} (${prop})`);
         }
       } else if (kind === PropFlags.Bool) {
         const v = buf[offset];
         offset += 1;
         // @ts-ignore dump fn
         // deno-lint-ignore no-console
-        console.log(`    ${name}: ${v} (${kindName}, ${prop})`);
+        console.error(`    ${name}: ${v} (${kindName}, ${prop})`);
       } else if (kind === PropFlags.String) {
         const v = readU32(buf, offset);
         offset += 4;
         // @ts-ignore dump fn
         // deno-lint-ignore no-console
-        console.log(
+        console.error(
           `    ${name}: ${getString(ctx.strTable, v)} (${kindName}, ${prop})`,
         );
       } else if (kind === PropFlags.Null) {
         // @ts-ignore dump fn
         // deno-lint-ignore no-console
-        console.log(`    ${name}: null (${kindName}, ${prop})`);
+        console.error(`    ${name}: null (${kindName}, ${prop})`);
       } else if (kind === PropFlags.Undefined) {
         // @ts-ignore dump fn
         // deno-lint-ignore no-console
-        console.log(`    ${name}: undefined (${kindName}, ${prop})`);
+        console.error(`    ${name}: undefined (${kindName}, ${prop})`);
       }
     }
   }

cli/js/40_lint_selector.js

@@ -180,7 +180,7 @@ export class Lexer {
       return;
     }
 
-    // console.log(
+    // console.error(
     //   "NEXT",
     //   this.input,
     //   this.i,
@@ -752,7 +752,7 @@ export function compileSelector(selector) {
       default:
         // @ts-ignore error handling
         // deno-lint-ignore no-console
-        console.log(node);
+        // console.error(node);
         throw new Error(`Unknown selector node`);
     }
   }

cli/lsp/analysis.rs

@@ -5,6 +5,7 @@ use super::diagnostics::DiagnosticSource;
 use super::documents::Document;
 use super::documents::Documents;
 use super::language_server;
+use super::logging::lsp_log;
 use super::resolver::LspResolver;
 use super::tsc;
 use super::urls::url_to_uri;
@@ -186,11 +187,12 @@ pub fn get_lint_references(
   linter: &CliLinter,
 ) -> Result<Vec<Reference>, AnyError> {
   let lint_diagnostics = linter.lint_with_ast(parsed_source);
-
+  lsp_log!("lint diagnostics {}", lint_diagnostics.len());
   Ok(
     lint_diagnostics
       .into_iter()
       .filter_map(|d| {
+        lsp_log!("range {:?}", d.range.as_ref().is_some());
         let range = d.range.as_ref()?;
         Some(Reference {
           range: as_lsp_range_from_lint_diagnostic(range),

cli/lsp/config.rs

@@ -1638,9 +1638,17 @@ impl ConfigData {
     let maybe_plugin_specifiers_result = lint_options.resolve_lint_plugins();
     if let Ok(maybe_plugin_specifiers) = maybe_plugin_specifiers_result {
       if let Some(plugin_specifiers) = maybe_plugin_specifiers {
+        fn logger_printer(msg: &str, _is_err: bool) {
+          lsp_log!("pluggin runner - {}", msg);
+        }
+        let logger =
+          crate::tools::lint::PluginLogger::new(logger_printer, true);
         let plugin_load_result =
-          crate::tools::lint::create_runner_and_load_plugins(plugin_specifiers)
+          crate::tools::lint::create_runner_and_load_plugins(
-            .await;
+            plugin_specifiers,
+            logger,
+          )
+          .await;
         // eprintln!("plugin load result {:#?}", plugin_load_result);
         if let Some(runner) = plugin_load_result.ok() {
           plugin_runner = Some(Arc::new(Mutex::new(runner)));

cli/lsp/language_server.rs

@@ -3090,6 +3090,7 @@ impl tower_lsp::LanguageServer for LanguageServer {
     self.init_flag.raise();
 
     for registration in registrations {
+      lsp_log!("{}", format!("registration {:#?}", registration));
       if let Err(err) = self
         .client
         .when_outside_lsp_lock()
@@ -3098,6 +3099,7 @@ impl tower_lsp::LanguageServer for LanguageServer {
       {
         lsp_warn!("Client errored on capabilities.\n{:#}", err);
       }
+      lsp_log!("registration finished");
     }
 
     if upgrade_check_enabled() {

cli/ops/lint.rs

@@ -14,6 +14,7 @@ use deno_lint::diagnostic::LintDiagnosticDetails;
 use deno_lint::diagnostic::LintDiagnosticRange;
 
 use crate::tools::lint;
+use crate::tools::lint::PluginLogger;
 
 deno_core::extension!(
   deno_lint_ext,
@@ -22,9 +23,17 @@ deno_core::extension!(
     op_lint_report,
     op_lint_get_source
   ],
-  state = |state| {
+  options = {
+    logger: PluginLogger,
+  },
+  middleware = |op| match op.name {
+    "op_print" => op_print(),
+    _ => op,
+  },
+  state = |state, options| {
+    state.put(options.logger);
     state.put(LintPluginContainer::default());
-  }
+  },
 );
 
 #[derive(Default)]
@@ -68,6 +77,17 @@ impl LintPluginContainer {
   }
 }
 
+#[op2(fast)]
+pub fn op_print(state: &mut OpState, #[string] msg: &str, is_err: bool) {
+  let logger = state.borrow::<PluginLogger>();
+
+  if is_err {
+    logger.error(msg);
+  } else {
+    logger.log(msg);
+  }
+}
+
 #[op2]
 #[buffer]
 fn op_lint_create_serialized_ast(

cli/tools/lint/linter.rs

@@ -111,13 +111,13 @@ impl CliLinter {
     let mut diagnostics = self
       .linter
       .lint_with_ast(parsed_source, self.deno_lint_config.clone());
-    eprintln!("lint with ast");
+    // eprintln!("lint with ast");
     let file_path = parsed_source.specifier().to_file_path().unwrap();
     // TODO(bartlomieju): surface error is running plugin fails
     let run_plugin_result = self.run_plugins(parsed_source.clone(), file_path);
-    // if let Err(err) = run_plugin_result.as_ref() {
+    if let Err(err) = run_plugin_result.as_ref() {
-    //   eprintln!("run plugin result {:#?}", err);
+      eprintln!("run plugin result {:#?}", err);
-    // }
+    }
     let maybe_plugin_diagnostics = run_plugin_result.ok();
     if let Some(plugin_diagnostics) = maybe_plugin_diagnostics {
       diagnostics.extend_from_slice(&plugin_diagnostics);

cli/tools/lint/mod.rs

@@ -62,6 +62,7 @@ pub use ast_buffer::serialize_ast_to_buffer;
 pub use linter::CliLinter;
 pub use linter::CliLinterOptions;
 pub use plugins::create_runner_and_load_plugins;
+pub use plugins::PluginLogger;
 pub use rules::collect_no_slow_type_diagnostics;
 pub use rules::ConfiguredRules;
 pub use rules::LintRuleProvider;
@@ -297,10 +298,20 @@ impl WorkspaceLinter {
         ))
       });
 
+    fn logger_printer(msg: &str, is_err: bool) {
+      if is_err {
+        eprintln!("{}", msg);
+      } else {
+        println!("{}", msg);
+      }
+    }
+
     let mut plugin_runner = None;
     if let Some(plugin_specifiers) = maybe_plugin_specifiers {
+      let logger = plugins::PluginLogger::new(logger_printer, true);
       let runner =
-        plugins::create_runner_and_load_plugins(plugin_specifiers).await?;
+        plugins::create_runner_and_load_plugins(plugin_specifiers, logger)
+          .await?;
       plugin_runner = Some(Arc::new(Mutex::new(runner)));
     }
 

cli/tools/lint/plugins.rs

@@ -10,6 +10,8 @@ use deno_core::resolve_url_or_path;
 use deno_core::v8;
 use deno_core::PollEventLoopOptions;
 use deno_lint::diagnostic::LintDiagnostic;
+use deno_runtime::deno_io::Stdio;
+use deno_runtime::deno_io::StdioPipe;
 use deno_runtime::deno_permissions::Permissions;
 use deno_runtime::deno_permissions::PermissionsContainer;
 use deno_runtime::tokio_util;
@@ -49,12 +51,45 @@ impl std::fmt::Debug for PluginRunnerResponse {
   }
 }
 
+#[derive(Clone)]
+pub struct PluginLogger {
+  print: fn(&str, bool),
+  debug: bool,
+}
+
+impl PluginLogger {
+  pub fn new(print: fn(&str, bool), debug: bool) -> Self {
+    Self { print, debug }
+  }
+
+  pub fn log(&self, msg: &str) {
+    (self.print)(msg, false);
+  }
+
+  pub fn error(&self, msg: &str) {
+    (self.print)(msg, true);
+  }
+
+  pub fn debug(&self, msg: &str) {
+    if self.debug {
+      (self.print)(msg, false);
+    }
+  }
+}
+
+impl std::fmt::Debug for PluginLogger {
+  fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+    f.debug_tuple("PluginLogger").field(&self.debug).finish()
+  }
+}
+
 #[derive(Debug)]
 pub struct PluginRunnerProxy {
   tx: Sender<PluginRunnerRequest>,
   rx: Arc<tokio::sync::Mutex<Receiver<PluginRunnerResponse>>>,
   #[allow(unused)]
   join_handle: std::thread::JoinHandle<Result<(), AnyError>>,
+  logger: PluginLogger,
 }
 
 pub struct PluginRunner {
@@ -63,16 +98,19 @@ pub struct PluginRunner {
   run_plugins_for_file_fn: v8::Global<v8::Function>,
   tx: Sender<PluginRunnerResponse>,
   rx: Receiver<PluginRunnerRequest>,
+  logger: PluginLogger,
 }
 
 impl PluginRunner {
-  fn create() -> Result<PluginRunnerProxy, AnyError> {
+  fn create(logger: PluginLogger) -> Result<PluginRunnerProxy, AnyError> {
     let (tx_req, rx_req) = channel(10);
     let (tx_res, rx_res) = channel(10);
 
-    log::debug!("spawning thread");
+    logger.log("spawning thread");
+    let logger_ = logger.clone();
     let join_handle = std::thread::spawn(move || {
-      log::debug!("PluginRunner thread spawned");
+      let logger = logger_;
+      logger.log("PluginRunner thread spawned");
       let start = std::time::Instant::now();
       let fut = async move {
         let flags = Flags {
@@ -94,25 +132,32 @@ impl PluginRunner {
         // let resolver = factory.resolver().await?.clone();
         let worker_factory = factory.create_cli_main_worker_factory().await?;
 
+        let dev_null = std::fs::File::open("/dev/null").unwrap();
+        let dev_null2 = std::fs::File::open("/dev/null").unwrap();
+
         let worker = worker_factory
           .create_custom_worker(
             // TODO(bartlomieju): add "lint" execution mode
             WorkerExecutionMode::Run,
             main_module.clone(),
             permissions,
-            vec![crate::ops::lint::deno_lint_ext::init_ops()],
+            vec![crate::ops::lint::deno_lint_ext::init_ops(logger.clone())],
-            Default::default(),
+            Stdio {
+              stdin: StdioPipe::inherit(),
+              stdout: StdioPipe::file(dev_null),
+              stderr: StdioPipe::file(dev_null2),
+            },
           )
           .await?;
 
         let mut worker = worker.into_main_worker();
         let runtime = &mut worker.js_runtime;
 
-        log::debug!("before loaded");
+        logger.log("before loaded");
 
         let obj = runtime.execute_script("lint.js", "Deno[Deno.internal]")?;
 
-        log::debug!("After plugin loaded, capturing exports");
+        logger.log("After plugin loaded, capturing exports");
         let (install_plugin_fn, run_plugins_for_file_fn) = {
           let scope = &mut runtime.handle_scope();
           let module_exports: v8::Local<v8::Object> =
@@ -148,34 +193,36 @@ impl PluginRunner {
           run_plugins_for_file_fn,
           tx: tx_res,
           rx: rx_req,
+          logger: logger.clone(),
         };
         // TODO(bartlomieju): send "host ready" message to the proxy
-        log::debug!("running host loop");
+        logger.log("running host loop");
         runner.run_loop().await?;
-        log::debug!(
+        logger.log(&format!(
           "PluginRunner thread finished, took {:?}",
           std::time::Instant::now() - start
-        );
+        ));
         Ok(())
       }
       .boxed_local();
       tokio_util::create_and_run_current_thread(fut)
     });
 
-    log::debug!("is thread finished {}", join_handle.is_finished());
+    logger.log(&format!("is thread finished {}", join_handle.is_finished()));
     let proxy = PluginRunnerProxy {
       tx: tx_req,
       rx: Arc::new(tokio::sync::Mutex::new(rx_res)),
       join_handle,
+      logger,
     };
 
     Ok(proxy)
   }
 
   async fn run_loop(mut self) -> Result<(), AnyError> {
-    log::info!("waiting for message");
+    self.logger.log("waiting for message");
     while let Some(req) = self.rx.recv().await {
-      log::info!("received message");
+      self.logger.log("received message");
       match req {
         PluginRunnerRequest::LoadPlugins(specifiers) => {
           let r = self.load_plugins(specifiers).await;
@@ -194,15 +241,15 @@ impl PluginRunner {
             Ok(()) => Ok(self.take_diagnostics()),
             Err(err) => Err(err),
           };
-          log::info!(
+          self.logger.log(&format!(
             "Running rules took {:?}",
             std::time::Instant::now() - start
-          );
+          ));
           let _ = self.tx.send(PluginRunnerResponse::Run(r)).await;
         }
       }
     }
-    log::info!("breaking loop");
+    self.logger.log("breaking loop");
     Ok(())
   }
 
@@ -256,11 +303,9 @@ impl PluginRunner {
       .with_event_loop_promise(call, PollEventLoopOptions::default())
       .await;
     match result {
-      Ok(_r) => {
+      Ok(_r) => self.logger.log("plugins finished"),
-        log::info!("plugins finished")
-      }
       Err(error) => {
-        log::info!("error running plugins {}", error);
+        self.logger.log(&format!("error running plugins {}", error));
       }
     }
 
@@ -302,10 +347,10 @@ impl PluginRunner {
         v8::Local::new(scope, self.install_plugin_fn.clone());
       let undefined = v8::undefined(scope);
       let args = &[default_export];
-      log::info!("Installing plugin...");
+      self.logger.log("Installing plugin...");
       // TODO(bartlomieju): do it in a try/catch scope
       install_plugins_local.call(scope, undefined.into(), args);
-      log::info!("Plugin installed");
+      self.logger.log("Plugin installed");
     }
 
     Ok(())
@@ -322,12 +367,14 @@ impl PluginRunnerProxy {
       .send(PluginRunnerRequest::LoadPlugins(plugin_specifiers))
       .await?;
     let mut rx = self.rx.lock().await;
-    log::debug!("receiving load plugins");
+    self.logger.log("receiving load plugins");
     if let Some(val) = rx.recv().await {
       let PluginRunnerResponse::LoadPlugin(result) = val else {
         unreachable!()
       };
-      log::info!("load plugins response {:#?}", result);
+      self
+        .logger
+        .error(&format!("load plugins response {:#?}", result));
       return Ok(());
     }
     Err(custom_error("AlreadyClosed", "Plugin host has closed"))
@@ -348,7 +395,7 @@ impl PluginRunnerProxy {
       ))
       .await?;
     let mut rx = self.rx.lock().await;
-    log::info!("receiving diagnostics");
+    self.logger.log("receiving diagnostics");
     if let Some(PluginRunnerResponse::Run(diagnostics_result)) = rx.recv().await
     {
       return diagnostics_result;
@@ -359,8 +406,9 @@ impl PluginRunnerProxy {
 
 pub async fn create_runner_and_load_plugins(
   plugin_specifiers: Vec<ModuleSpecifier>,
+  logger: PluginLogger,
 ) -> Result<PluginRunnerProxy, AnyError> {
-  let runner_proxy = PluginRunner::create()?;
+  let runner_proxy = PluginRunner::create(logger)?;
   runner_proxy.load_plugins(plugin_specifiers).await?;
   Ok(runner_proxy)
 }
@@ -380,9 +428,9 @@ pub async fn run_rules_for_ast(
 pub fn serialize_ast(parsed_source: ParsedSource) -> Result<Vec<u8>, AnyError> {
   let start = std::time::Instant::now();
   let r = serialize_ast_to_buffer(&parsed_source);
-  log::info!(
+  // log::info!(
-    "serialize custom ast took {:?}",
+  //   "serialize custom ast took {:?}",
-    std::time::Instant::now() - start
+  //   std::time::Instant::now() - start
-  );
+  // );
   Ok(r)
 }

cli/tools/test/mod.rs

@@ -611,6 +611,14 @@ async fn configure_main_worker(
   worker_sender: TestEventWorkerSender,
   options: &TestSpecifierOptions,
 ) -> Result<(Option<Box<dyn CoverageCollector>>, MainWorker), anyhow::Error> {
+  fn linter_logger(msg: &str, is_err: bool) {
+    if is_err {
+      eprintln!("{}", msg);
+    } else {
+      println!("{}", msg);
+    }
+  }
+  let logger = crate::tools::lint::PluginLogger::new(linter_logger, true);
   let mut worker = worker_factory
     .create_custom_worker(
       WorkerExecutionMode::Test,
@@ -619,7 +627,7 @@ async fn configure_main_worker(
       vec![
         ops::testing::deno_test::init_ops(worker_sender.sender),
         // TODO(bartlomieju): this is temporary and should be removed before landing plugin support
-        ops::lint::deno_lint_ext::init_ops(),
+        ops::lint::deno_lint_ext::init_ops(logger),
       ],
       Stdio {
         stdin: StdioPipe::inherit(),