Clean up logging and make it work (#65)

Author: blopker

Makefile

@@ -17,7 +17,7 @@ integration_test: build
 # Build and install dev version into Zed's extension directory for testing
 install_ext: generate_word_list
 	cd crates/codebook-lsp && cargo build --profile=fast-release
-	cp -f target/release/codebook-lsp "${HOME}/Library/Application Support/Zed/extensions/work/codebook/"
+	cp -f target/fast-release/codebook-lsp "${HOME}/Library/Application Support/Zed/extensions/work/codebook/"
 
 uninstall_ext:
 	rm -f "${HOME}/Library/Application Support/Zed/extensions/work/codebook/codebook-lsp"

crates/codebook-config/src/lib.rs

@@ -60,7 +60,7 @@ impl Default for CodebookConfig {
 impl CodebookConfig {
     /// Load configuration by searching for both global and project-specific configs
     pub fn load(current_dir: Option<&Path>) -> Result<Self, io::Error> {
-        info!("Initializing CodebookConfig");
+        debug!("Initializing CodebookConfig");
 
         if let Some(current_dir) = current_dir {
             let current_dir = Path::new(current_dir);
@@ -81,7 +81,7 @@ impl CodebookConfig {
             if global_path.exists() {
                 match Self::load_settings_from_file(&global_path) {
                     Ok(global_settings) => {
-                        info!("Loaded global config from {}", global_path.display());
+                        debug!("Loaded global config from {}", global_path.display());
                         config.global_config_path = Some(global_path.clone());
                         *config.global_settings.write().unwrap() = Some(global_settings.clone());
                         *config.effective_settings.write().unwrap() = global_settings;
@@ -109,7 +109,7 @@ impl CodebookConfig {
 
         // Then try to find and load project config
         if let Some((project_path, project_settings)) = Self::find_project_config(start_dir)? {
-            info!("Loaded project config from {}", project_path.display());
+            debug!("Loaded project config from {}", project_path.display());
             config.project_config_path = Some(project_path.clone());
             *config.project_settings.write().unwrap() = project_settings.clone();
 
@@ -440,7 +440,7 @@ impl CodebookConfig {
 
         let content = toml::to_string_pretty(&*self.project_settings.read().unwrap())
             .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;
-        log::info!(
+        info!(
             "Saving project configuration to {}",
             project_config_path.display()
         );
@@ -456,7 +456,7 @@ impl CodebookConfig {
 
         let content = toml::to_string_pretty(&*self.global_settings.read().unwrap())
             .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;
-        log::info!(
+        info!(
             "Saving project configuration to {}",
             global_config_path.display()
         );

crates/codebook-lsp/Cargo.toml

@@ -9,7 +9,7 @@ tower-lsp.workspace = true
 serde.workspace = true
 serde_json.workspace = true
 fs2.workspace = true
-tokio.workspace = true
+tokio = { workspace = true, features = ["sync", "rt"] }
 env_logger.workspace = true
 log.workspace = true
 clap.workspace = true

crates/codebook-lsp/src/lsp.rs

@@ -7,6 +7,7 @@ use codebook::parser::TextRange;
 use codebook::parser::WordLocation;
 use codebook::parser::get_word_from_string;
 use codebook::queries::LanguageType;
+use log::LevelFilter;
 use log::error;
 use serde_json::Value;
 use tokio::task;
@@ -19,6 +20,7 @@ use codebook_config::CodebookConfig;
 use log::{debug, info};
 
 use crate::file_cache::TextDocumentCache;
+use crate::lsp_logger;
 
 const SOURCE_NAME: &str = "Codebook";
 
@@ -58,8 +60,24 @@ impl From<CodebookCommand> for String {
 
 #[tower_lsp::async_trait]
 impl LanguageServer for Backend {
-    async fn initialize(&self, _: InitializeParams) -> RpcResult<InitializeResult> {
-        info!("Server initialized");
+    async fn initialize(&self, params: InitializeParams) -> RpcResult<InitializeResult> {
+        // Get log level from initialization options
+        let log_level = params
+            .initialization_options
+            .as_ref()
+            .and_then(|options| options.get("logLevel"))
+            .and_then(|level| level.as_str())
+            .map(|level| {
+                if level == "debug" {
+                    LevelFilter::Debug
+                } else {
+                    LevelFilter::Info
+                }
+            })
+            .unwrap_or(LevelFilter::Info);
+        lsp_logger::LspLogger::init(self.client.clone(), log_level)
+            .expect("Failed to initialize LSP logger");
+        info!("LSP logger initialized with log level: {}", log_level);
         Ok(InitializeResult {
             capabilities: ServerCapabilities {
                 text_document_sync: Some(TextDocumentSyncCapability::Kind(
@@ -313,10 +331,10 @@ impl Backend {
                     should_save = true;
                 }
                 Ok(false) => {
-                    log::info!("Word '{}' already exists in dictionary.", word);
+                    info!("Word '{}' already exists in dictionary.", word);
                 }
                 Err(e) => {
-                    log::error!("Failed to add word: {}", e);
+                    error!("Failed to add word: {}", e);
                 }
             }
         }
@@ -330,10 +348,10 @@ impl Backend {
                     should_save = true;
                 }
                 Ok(false) => {
-                    log::info!("Word '{}' already exists in global dictionary.", word);
+                    info!("Word '{}' already exists in global dictionary.", word);
                 }
                 Err(e) => {
-                    log::error!("Failed to add word: {}", e);
+                    error!("Failed to add word: {}", e);
                 }
             }
         }
@@ -379,7 +397,7 @@ impl Backend {
         let did_reload = match self.config.reload() {
             Ok(did_reload) => did_reload,
             Err(e) => {
-                log::error!("Failed to reload config: {}", e);
+                error!("Failed to reload config: {}", e);
                 false
             }
         };
@@ -399,7 +417,7 @@ impl Backend {
         };
         // Convert the file URI to a local file path.
         let file_path = doc.uri.to_file_path().unwrap_or_default();
-        info!("Spell-checking file: {:?}", file_path);
+        debug!("Spell-checking file: {:?}", file_path);
         // 1) Perform spell-check.
         let lang_type = doc
             .language_id
@@ -438,11 +456,11 @@ impl Backend {
             })
             .collect();
 
-        debug!("Diagnostics: {:?}", diagnostics);
+        // debug!("Diagnostics: {:?}", diagnostics);
         // 3) Send the diagnostics to the client.
         self.client
             .publish_diagnostics(doc.uri, diagnostics, None)
             .await;
-        debug!("Published diagnostics for: {:?}", file_path);
+        // debug!("Published diagnostics for: {:?}", file_path);
     }
 }

crates/codebook-lsp/src/lsp_logger.rs

@@ -0,0 +1,70 @@
+use log::{Level, LevelFilter, Log, Metadata, Record};
+use tokio::sync::mpsc::{self, Sender};
+use tower_lsp::Client;
+use tower_lsp::lsp_types::MessageType;
+
+pub struct LspLogger {
+    sender: Sender<LogMessage>,
+    level: LevelFilter,
+}
+
+struct LogMessage {
+    level: Level,
+    message: String,
+}
+
+impl LspLogger {
+    pub fn init(client_clone: Client, level: LevelFilter) -> Result<(), log::SetLoggerError> {
+        // Create a channel for log messages
+        let (sender, mut receiver) = mpsc::channel::<LogMessage>(100);
+
+        // Create a new logger
+        let logger = Self { sender, level };
+
+        // Set up a background task to send logs to LSP client
+        tokio::spawn(async move {
+            while let Some(log_msg) = receiver.recv().await {
+                let lsp_level = match log_msg.level {
+                    Level::Error => MessageType::ERROR,
+                    Level::Warn => MessageType::WARNING,
+                    Level::Info => MessageType::INFO,
+                    Level::Debug | Level::Trace => MessageType::LOG,
+                };
+
+                // Ignore any errors from sending log messages
+                let _ = client_clone.log_message(lsp_level, log_msg.message).await;
+            }
+        });
+
+        // Register our custom logger
+        log::set_boxed_logger(Box::new(logger)).map(|()| log::set_max_level(level))
+    }
+}
+
+impl Log for LspLogger {
+    fn enabled(&self, metadata: &Metadata) -> bool {
+        metadata.level() <= self.level
+    }
+
+    fn log(&self, record: &Record) {
+        if !self.enabled(record.metadata()) {
+            return;
+        }
+
+        // Format the log message with module path
+        let message = format!(
+            "[{}] {}: {}",
+            record.target(),
+            record.level(),
+            record.args()
+        );
+
+        // Send log message to channel, ignore if channel is full
+        let _ = self.sender.try_send(LogMessage {
+            level: record.level(),
+            message,
+        });
+    }
+
+    fn flush(&self) {}
+}

crates/codebook-lsp/src/main.rs

@@ -1,5 +1,7 @@
 mod file_cache;
 mod lsp;
+mod lsp_logger;
+
 use clap::{Parser, Subcommand};
 use codebook_config::CodebookConfig;
 use log::info;
@@ -30,8 +32,6 @@ enum Commands {
 
 #[tokio::main(flavor = "current_thread")]
 async fn main() {
-    // Initialize logging so we can see server messages in the console.
-    env_logger::init();
     let cli = Cli::parse();
 
     let root = match cli.root.as_deref() {
@@ -53,13 +53,15 @@ async fn main() {
 }
 
 async fn serve_lsp(root: &Path) {
-    info!("Starting Codebook Language Server...");
+    eprintln!("Starting Codebook Language Server..");
     let (stdin, stdout) = (tokio::io::stdin(), tokio::io::stdout());
     let inner_root = root.to_owned();
+
     // Some blocking setup is done, so spawn_block!
     let (service, socket) =
         task::spawn_blocking(move || LspService::new(|client| Backend::new(client, &inner_root)))
             .await
             .unwrap();
+
     Server::new(stdin, stdout, socket).serve(service).await;
 }

crates/codebook/src/dictionaries/dictionary.rs

@@ -1,4 +1,3 @@
-use log::debug;
 use lru::LruCache;
 
 use std::{
@@ -77,10 +76,10 @@ impl Dictionary for HunspellDictionary {
     }
 
     fn suggest(&self, word: &str) -> Vec<String> {
-        debug!("Checking Cache: {:?}", word);
+        // debug!("Checking Cache: {:?}", word);
         // First try to get from cache with write lock since get() needs to modify LRU order
         if let Some(suggestions) = self.suggestion_cache.write().unwrap().get_mut(word) {
-            debug!("Cache hit for {:?}", word);
+            // debug!("Cache hit for {:?}", word);
             return suggestions.clone();
         }
 

crates/codebook/src/dictionaries/manager.rs

@@ -6,11 +6,11 @@ use std::{
 
 use super::{
     dictionary::{self, TextDictionary},
-    repo::{get_repo, DictionaryRepo, HunspellRepo, TextRepo},
+    repo::{DictionaryRepo, HunspellRepo, TextRepo, get_repo},
 };
 use dictionary::{Dictionary, HunspellDictionary};
 use downloader::Downloader;
-use log::info;
+use log::{debug, error};
 
 pub struct DictionaryManager {
     dictionary_cache: Arc<RwLock<HashMap<String, Arc<dyn Dictionary>>>>,
@@ -33,7 +33,7 @@ impl DictionaryManager {
         let repo = match get_repo(id) {
             Some(r) => r,
             None => {
-                info!("Failed to get repo for dictionary: {}", id);
+                debug!("Failed to get repo for dictionary, skipping: {}", id);
                 return None;
             }
         };
@@ -56,22 +56,22 @@ impl DictionaryManager {
         let aff_path = match self.downloader.get(&repo.aff_url) {
             Ok(path) => path,
             Err(e) => {
-                info!("Error: {:?}", e);
+                error!("Error: {:?}", e);
                 return None;
             }
         };
         let dic_path = match self.downloader.get(&repo.dict_url) {
             Ok(path) => path,
             Err(e) => {
-                info!("Error: {:?}", e);
+                error!("Error: {:?}", e);
                 return None;
             }
         };
         let dict =
             match HunspellDictionary::new(aff_path.to_str().unwrap(), dic_path.to_str().unwrap()) {
                 Ok(dict) => dict,
                 Err(e) => {
-                    info!("Error: {:?}", e);
+                    error!("Error: {:?}", e);
                     return None;
                 }
             };
@@ -85,7 +85,7 @@ impl DictionaryManager {
         let text_path = match self.downloader.get(&repo.url.unwrap()) {
             Ok(path) => path,
             Err(e) => {
-                info!("Error: {:?}", e);
+                error!("Error: {:?}", e);
                 return None;
             }
         };

crates/codebook/src/lib.rs

@@ -9,7 +9,7 @@ use std::sync::Arc;
 use codebook_config::CodebookConfig;
 use dictionaries::{dictionary, manager::DictionaryManager};
 use dictionary::Dictionary;
-use log::info;
+use log::debug;
 use parser::WordLocation;
 
 pub struct Codebook {
@@ -87,7 +87,7 @@ impl Codebook {
         };
         dictionary_ids.extend(DEFAULT_DICTIONARIES.iter().map(|f| f.to_string()));
         let mut dictionaries = Vec::with_capacity(dictionary_ids.len());
-        info!("Checking text with dictionaries: {:?}", dictionary_ids);
+        debug!("Checking text with dictionaries: {:?}", dictionary_ids);
         for dictionary_id in dictionary_ids {
             let dictionary = self.manager.get_dictionary(&dictionary_id);
             if let Some(d) = dictionary {

crates/codebook/src/parser.rs

@@ -1,5 +1,4 @@
 use crate::splitter::{self};
-use log::debug;
 
 use crate::queries::{LanguageType, get_language_setting};
 use std::collections::HashMap;
@@ -87,12 +86,12 @@ fn find_locations_code(
             let current_line = node_start.row as u32;
             let current_column = node_start.column as u32;
             let words = get_words_from_text(node_text);
-            debug!("Found Capture: {node_text:?}");
-            debug!("Words: {words:?}");
-            debug!("Column: {current_column}");
-            debug!("Line: {current_line}");
+            // debug!("Found Capture: {node_text:?}");
+            // debug!("Words: {words:?}");
+            // debug!("Column: {current_column}");
+            // debug!("Line: {current_line}");
             for (word_text, (text_start_char, text_line)) in words {
-                debug!("Checking: {:?}", word_text);
+                // debug!("Checking: {:?}", word_text);
                 if !check_function(&word_text) {
                     let offset = if text_line == 0 { current_column } else { 0 };
                     let base_start_char = text_start_char + offset;