feat: add debugging to item service

Co-authored-by: aider (openai/andrew/openrouter/anthropic/claude-sonnet-4) <aider@aider.chat>

src/services/item_service.rs

@@ -8,6 +8,7 @@ use crate::db::{self, Meta};
 use crate::compression_engine::{get_compression_engine, CompressionType};
 use crate::modes::common::settings_compression_type;
 use clap::Command;
+use log::debug;
 use rusqlite::Connection;
 use std::collections::HashMap;
 use std::fs;
@@ -22,6 +23,7 @@ pub struct ItemService {
 
 impl ItemService {
     pub fn new(data_path: PathBuf) -> Self {
+        debug!("ITEM_SERVICE: Creating new ItemService with data_path: {:?}", data_path);
         Self {
             data_path,
             compression_service: CompressionService::new(),
@@ -30,13 +32,18 @@ impl ItemService {
     }
 
     pub fn get_item(&self, conn: &Connection, id: i64) -> Result<ItemWithMeta, CoreError> {
+        debug!("ITEM_SERVICE: Getting item with id: {}", id);
         let item = db::get_item(conn, id)?.ok_or(CoreError::ItemNotFound(id))?;
+        debug!("ITEM_SERVICE: Found item: {:?}", item);
         let tags = db::get_item_tags(conn, &item)?;
+        debug!("ITEM_SERVICE: Found {} tags for item {}", tags.len(), id);
         let meta = db::get_item_meta(conn, &item)?;
+        debug!("ITEM_SERVICE: Found {} meta entries for item {}", meta.len(), id);
         Ok(ItemWithMeta { item, tags, meta })
     }
 
     pub fn get_item_content(&self, conn: &Connection, id: i64) -> Result<ItemWithContent, CoreError> {
+        debug!("ITEM_SERVICE: Getting item content for id: {}", id);
         let item_with_meta = self.get_item(conn, id)?;
         let item_id = item_with_meta.item.id.ok_or_else(|| CoreError::InvalidInput("Item missing ID".to_string()))?;
 
@@ -46,10 +53,12 @@ impl ItemService {
 
         let mut item_path = self.data_path.clone();
         item_path.push(item_id.to_string());
+        debug!("ITEM_SERVICE: Reading content from path: {:?}", item_path);
         
         let content = self
             .compression_service
             .get_item_content(item_path, &item_with_meta.item.compression)?;
+        debug!("ITEM_SERVICE: Read {} bytes of content for item {}", content.len(), id);
         
         Ok(ItemWithContent {
             item_with_meta,
@@ -58,25 +67,40 @@ impl ItemService {
     }
 
     pub fn find_item(&self, conn: &Connection, ids: &[i64], tags: &[String], meta: &HashMap<String, String>) -> Result<ItemWithMeta, CoreError> {
-         let item_maybe = match (ids.is_empty(), tags.is_empty() && meta.is_empty()) {
+        debug!("ITEM_SERVICE: Finding item with ids: {:?}, tags: {:?}, meta: {:?}", ids, tags, meta);
-            (false, _) => db::get_item(conn, ids[0])?,
+        let item_maybe = match (ids.is_empty(), tags.is_empty() && meta.is_empty()) {
-            (true, true) => db::get_item_last(conn)?,
+            (false, _) => {
-            (true, false) => db::get_item_matching(conn, &tags.to_vec(), meta)?
+                debug!("ITEM_SERVICE: Finding by ID: {}", ids[0]);
+                db::get_item(conn, ids[0])?
+            },
+            (true, true) => {
+                debug!("ITEM_SERVICE: Finding last item");
+                db::get_item_last(conn)?
+            },
+            (true, false) => {
+                debug!("ITEM_SERVICE: Finding by tags/meta");
+                db::get_item_matching(conn, &tags.to_vec(), meta)?
+            }
         };
 
         let item = item_maybe.ok_or(CoreError::ItemNotFoundGeneric)?;
+        debug!("ITEM_SERVICE: Found matching item: {:?}", item);
         let item_id = item.id.ok_or_else(|| CoreError::InvalidInput("Item missing ID".to_string()))?;
         self.get_item(conn, item_id)
     }
 
     pub fn list_items(&self, conn: &Connection, tags: &[String], meta: &HashMap<String, String>) -> Result<Vec<ItemWithMeta>, CoreError> {
+        debug!("ITEM_SERVICE: Listing items with tags: {:?}, meta: {:?}", tags, meta);
         let items = db::get_items_matching(conn, &tags.to_vec(), meta)?;
+        debug!("ITEM_SERVICE: Found {} matching items", items.len());
         
         let item_ids: Vec<i64> = items.iter().filter_map(|item| item.id).collect();
         if item_ids.is_empty() {
+            debug!("ITEM_SERVICE: No items found, returning empty list");
             return Ok(Vec::new());
         }
 
+        debug!("ITEM_SERVICE: Getting tags and meta for {} items", item_ids.len());
         let tags_map = db::get_tags_for_items(conn, &item_ids)?;
         let meta_map_db = db::get_meta_for_items(conn, &item_ids)?;
         
@@ -90,22 +114,27 @@ impl ItemService {
             result.push(ItemWithMeta { item, tags, meta });
         }
         
+        debug!("ITEM_SERVICE: Returning {} items with full metadata", result.len());
         Ok(result)
     }
 
     pub fn delete_item(&self, conn: &mut Connection, id: i64) -> Result<(), CoreError> {
+        debug!("ITEM_SERVICE: Deleting item with id: {}", id);
         if id <= 0 {
             return Err(CoreError::InvalidInput(format!("Invalid item ID: {}", id)));
         }
         let item = db::get_item(conn, id)?.ok_or(CoreError::ItemNotFound(id))?;
+        debug!("ITEM_SERVICE: Found item to delete: {:?}", item);
 
         let mut item_path = self.data_path.clone();
         item_path.push(id.to_string());
+        debug!("ITEM_SERVICE: Deleting file at path: {:?}", item_path);
 
         let tx = conn.transaction()?;
         db::delete_item(&tx, item)?;
         fs::remove_file(&item_path).or_else(|e| if e.kind() == std::io::ErrorKind::NotFound { Ok(()) } else { Err(e) })?;
         tx.commit()?;
+        debug!("ITEM_SERVICE: Successfully deleted item {}", id);
 
         Ok(())
     }
@@ -118,11 +147,14 @@ impl ItemService {
         tags: &mut Vec<String>,
         conn: &mut Connection,
     ) -> Result<ItemWithMeta, CoreError> {
+        debug!("ITEM_SERVICE: Starting save_item with tags: {:?}", tags);
         if tags.is_empty() {
              tags.push("none".to_string());
+             debug!("ITEM_SERVICE: No tags provided, using default 'none' tag");
         }
 
         let compression_type = settings_compression_type(cmd, settings);
+        debug!("ITEM_SERVICE: Using compression type: {:?}", compression_type);
         let compression_engine = get_compression_engine(compression_type.clone())?;
 
         let tx = conn.transaction()?;
@@ -132,24 +164,30 @@ impl ItemService {
         {
             item = db::create_item(&tx, compression_type.clone())?;
             item_id = item.id.unwrap();
+            debug!("ITEM_SERVICE: Created new item with id: {}", item_id);
             db::set_item_tags(&tx, item.clone(), tags)?;
+            debug!("ITEM_SERVICE: Set tags for item {}", item_id);
             let item_meta = self.meta_service.collect_initial_meta();
+            debug!("ITEM_SERVICE: Collected {} initial meta entries", item_meta.len());
             for (k, v) in item_meta.iter() {
                db::add_meta(&tx, item_id, k, v)?;
             }
         }
         
         let mut plugins = self.meta_service.get_plugins(cmd, settings);
+        debug!("ITEM_SERVICE: Got {} meta plugins", plugins.len());
         self.meta_service.initialize_plugins(&mut plugins, &tx, item_id);
         
         let mut item_path = self.data_path.clone();
         item_path.push(item_id.to_string());
+        debug!("ITEM_SERVICE: Writing item to path: {:?}", item_path);
         
         let mut item_out = compression_engine.create(item_path.clone())?;
         
         let mut buffer = [0; 8192];
         let mut total_bytes = 0;
 
+        debug!("ITEM_SERVICE: Starting to read and process input data");
         loop {
             let n = input.read(&mut buffer)?;
             if n == 0 { break; }
@@ -158,16 +196,19 @@ impl ItemService {
             item_out.write_all(&buffer[..n])?;
             self.meta_service.process_chunk(&mut plugins, &buffer[..n], &tx);
         }
+        debug!("ITEM_SERVICE: Processed {} bytes total", total_bytes);
         
         item_out.flush()?;
         drop(item_out);
 
+        debug!("ITEM_SERVICE: Finalizing meta plugins");
         self.meta_service.finalize_plugins(&mut plugins, &tx);
         
         item.size = Some(total_bytes);
         db::update_item(&tx, item.clone())?;
         
         tx.commit()?;
+        debug!("ITEM_SERVICE: Transaction committed successfully");
 
         if !settings.quiet {
             if std::io::stderr().is_terminal() {
@@ -192,6 +233,7 @@ impl ItemService {
             }
         }
         
+        debug!("ITEM_SERVICE: Getting final item with metadata");
         self.get_item(conn, item_id)
     }
 
@@ -202,6 +244,8 @@ impl ItemService {
         metadata: &HashMap<String, String>,
         conn: &mut Connection,
     ) -> Result<ItemWithMeta, CoreError> {
+        debug!("ITEM_SERVICE: Starting save_item_from_mcp with {} bytes, {} tags, {} metadata entries", 
+               content.len(), tags.len(), metadata.len());
         let compression_type = CompressionType::LZ4;
         let compression_engine = get_compression_engine(compression_type.clone())?;
 
@@ -212,20 +256,24 @@ impl ItemService {
         {
             item = db::create_item(&tx, compression_type.clone())?;
             item_id = item.id.unwrap();
+            debug!("ITEM_SERVICE: Created MCP item with id: {}", item_id);
 
             // Add tags
             for tag in tags {
                 db::add_tag(&tx, item_id, tag)?;
             }
+            debug!("ITEM_SERVICE: Added {} tags to MCP item", tags.len());
 
             // Add custom metadata
             for (key, value) in metadata {
                 db::add_meta(&tx, item_id, key, value)?;
             }
+            debug!("ITEM_SERVICE: Added {} custom metadata entries to MCP item", metadata.len());
         }
 
         let mut item_path = self.data_path.clone();
         item_path.push(item_id.to_string());
+        debug!("ITEM_SERVICE: Writing MCP item to path: {:?}", item_path);
 
         let mut writer = compression_engine.create(item_path.clone())?;
         writer.write_all(content)?;
@@ -245,17 +293,20 @@ impl ItemService {
 
         let mut plugins: Vec<Box<dyn MetaPlugin>> =
             plugin_types.iter().map(|p| get_meta_plugin(p.clone())).collect();
+        debug!("ITEM_SERVICE: Created {} meta plugins for MCP item", plugins.len());
 
         self.meta_service
             .initialize_plugins(&mut plugins, &tx, item_id);
         self.meta_service
             .process_chunk(&mut plugins, content, &tx);
         self.meta_service.finalize_plugins(&mut plugins, &tx);
+        debug!("ITEM_SERVICE: Processed MCP item through meta plugins");
 
         item.size = Some(content.len() as i64);
         db::update_item(&tx, item.clone())?;
 
         tx.commit()?;
+        debug!("ITEM_SERVICE: MCP item transaction committed successfully");
 
         self.get_item(conn, item_id)
     }