@@ -10,6 +10,8 @@ use std::num::NonZeroUsize;
1010use std:: sync:: Arc ;
1111use tracing:: { debug, info} ;
1212
13+ const TOOL_PROGRESS_LOG_TARGET : & str = "codegraph::mcp::tools" ;
14+
1315use crate :: error:: McpError ;
1416use crate :: graph_tool_schemas:: GraphToolSchemas ;
1517use crate :: Result ;
@@ -114,8 +116,7 @@ impl GraphToolExecutor {
114116 /// # Returns
115117 /// JSON result from the tool execution
116118 pub async fn execute ( & self , tool_name : & str , parameters : JsonValue ) -> Result < JsonValue > {
117- info ! ( "Executing graph tool: {}" , tool_name) ;
118- debug ! ( "Tool parameters: {}" , parameters) ;
119+ log_tool_call_start ( tool_name, & parameters) ;
119120
120121 // Validate tool exists
121122 let _schema = GraphToolSchemas :: get_by_name ( tool_name)
@@ -133,7 +134,9 @@ impl GraphToolExecutor {
133134 let mut stats = self . cache_stats . lock ( ) ;
134135 stats. hits += 1 ;
135136 debug ! ( "Cache hit for {}: {}" , tool_name, cache_key) ;
136- return Ok ( cached_result. clone ( ) ) ;
137+ let cached = cached_result. clone ( ) ;
138+ log_tool_call_finish ( tool_name, & cached) ;
139+ return Ok ( cached) ;
137140 }
138141 }
139142
@@ -187,7 +190,7 @@ impl GraphToolExecutor {
187190 stats. current_size = cache. len ( ) ;
188191 }
189192
190- info ! ( "Tool execution complete: {}" , tool_name ) ;
193+ log_tool_call_finish ( tool_name , & result ) ;
191194 Ok ( result)
192195 }
193196
@@ -349,6 +352,34 @@ impl GraphToolExecutor {
349352 }
350353}
351354
355+ fn log_tool_call_start ( tool_name : & str , parameters : & JsonValue ) {
356+ info ! (
357+ target: TOOL_PROGRESS_LOG_TARGET ,
358+ tool = tool_name,
359+ "Tool call started"
360+ ) ;
361+ debug ! (
362+ target: TOOL_PROGRESS_LOG_TARGET ,
363+ tool = tool_name,
364+ "Tool input payload: {}" ,
365+ parameters
366+ ) ;
367+ }
368+
369+ fn log_tool_call_finish ( tool_name : & str , result : & JsonValue ) {
370+ info ! (
371+ target: TOOL_PROGRESS_LOG_TARGET ,
372+ tool = tool_name,
373+ "Tool call completed"
374+ ) ;
375+ debug ! (
376+ target: TOOL_PROGRESS_LOG_TARGET ,
377+ tool = tool_name,
378+ "Tool output payload: {}" ,
379+ result
380+ ) ;
381+ }
382+
352383#[ cfg( test) ]
353384mod tests {
354385 use super :: * ;
@@ -447,4 +478,98 @@ mod tests {
447478
448479 assert_eq ! ( stats. hit_rate( ) , 0.0 ) ;
449480 }
481+
482+ #[ test]
483+ fn test_log_tool_call_start_captures_info_and_debug ( ) {
484+ let logs = capture_logs ( || {
485+ let params = serde_json:: json!( {
486+ "node_id" : "nodes:123" ,
487+ "edge_type" : "Calls"
488+ } ) ;
489+ log_tool_call_start ( "get_transitive_dependencies" , & params) ;
490+ } ) ;
491+
492+ assert ! ( logs. contains( "Tool call started" ) ) ;
493+ assert ! ( logs. contains( "Tool input payload" ) ) ;
494+ }
495+
496+ #[ test]
497+ fn test_log_tool_call_finish_captures_info_and_debug ( ) {
498+ let logs = capture_logs ( || {
499+ let result = serde_json:: json!( {
500+ "tool" : "detect_cycles" ,
501+ "result" : "ok"
502+ } ) ;
503+ log_tool_call_finish ( "detect_cycles" , & result) ;
504+ } ) ;
505+
506+ assert ! ( logs. contains( "Tool call completed" ) ) ;
507+ assert ! ( logs. contains( "Tool output payload" ) ) ;
508+ }
509+
510+ fn capture_logs < F > ( f : F ) -> String
511+ where
512+ F : FnOnce ( ) ,
513+ {
514+ use std:: io:: Write ;
515+ use std:: sync:: { Arc , Mutex } ;
516+ use tracing:: subscriber:: with_default;
517+ use tracing_subscriber:: EnvFilter ;
518+
519+ #[ derive( Clone ) ]
520+ struct BufferWriter {
521+ inner : Arc < Mutex < Vec < u8 > > > ,
522+ }
523+
524+ impl BufferWriter {
525+ fn new ( ) -> Self {
526+ Self {
527+ inner : Arc :: new ( Mutex :: new ( Vec :: new ( ) ) ) ,
528+ }
529+ }
530+
531+ fn into_string ( & self ) -> String {
532+ let bytes = self . inner . lock ( ) . unwrap ( ) . clone ( ) ;
533+ String :: from_utf8 ( bytes) . unwrap ( )
534+ }
535+ }
536+
537+ impl < ' a > tracing_subscriber:: fmt:: MakeWriter < ' a > for BufferWriter {
538+ type Writer = BufferGuard ;
539+
540+ fn make_writer ( & ' a self ) -> Self :: Writer {
541+ BufferGuard {
542+ inner : self . inner . clone ( ) ,
543+ }
544+ }
545+ }
546+
547+ struct BufferGuard {
548+ inner : Arc < Mutex < Vec < u8 > > > ,
549+ }
550+
551+ impl Write for BufferGuard {
552+ fn write ( & mut self , buf : & [ u8 ] ) -> std:: io:: Result < usize > {
553+ self . inner . lock ( ) . unwrap ( ) . extend_from_slice ( buf) ;
554+ Ok ( buf. len ( ) )
555+ }
556+
557+ fn flush ( & mut self ) -> std:: io:: Result < ( ) > {
558+ Ok ( ( ) )
559+ }
560+ }
561+
562+ let writer = BufferWriter :: new ( ) ;
563+
564+ let subscriber = tracing_subscriber:: fmt ( )
565+ . with_env_filter ( EnvFilter :: new ( "debug" ) )
566+ . with_ansi ( false )
567+ . without_time ( )
568+ . with_writer ( writer. clone ( ) )
569+ . finish ( ) ;
570+
571+ with_default ( subscriber, f) ;
572+
573+ writer. into_string ( )
574+ }
450575}
0 commit comments