refactor: Add logging to TemplateEngineHelper and DotNetCliTools for better traceability

Author: jongalloway

DotNetMcp/DotNetCliTools.cs

@@ -1,6 +1,7 @@
 using System.ComponentModel;
 using System.Diagnostics;
 using System.Text;
+using Microsoft.Extensions.Logging;
 using ModelContextProtocol.Protocol;
 using ModelContextProtocol.Server;
 
@@ -9,24 +10,30 @@ namespace DotNetMcp;
 [McpServerToolType]
 public sealed class DotNetCliTools
 {
+    private readonly ILogger<DotNetCliTools> _logger;
+
+    public DotNetCliTools(ILogger<DotNetCliTools> logger)
+    {
+        _logger = logger;
+    }
     [McpServerTool, Description("List all installed .NET templates with their metadata using the Template Engine. Provides structured information about available project templates.")]
     public async Task<string> DotnetTemplateList()
-        => await TemplateEngineHelper.GetInstalledTemplatesAsync();
+        => await TemplateEngineHelper.GetInstalledTemplatesAsync(_logger);
 
     [McpServerTool, Description("Search for .NET templates by name or description. Returns matching templates with their details.")]
     public async Task<string> DotnetTemplateSearch(
         [Description("Search term to find templates (searches in name, short name, and description)")] string searchTerm)
-        => await TemplateEngineHelper.SearchTemplatesAsync(searchTerm);
+        => await TemplateEngineHelper.SearchTemplatesAsync(searchTerm, _logger);
 
     [McpServerTool, Description("Get detailed information about a specific template including available parameters and options.")]
     public async Task<string> DotnetTemplateInfo(
         [Description("The template short name (e.g., 'console', 'webapi', 'classlib')")] string templateShortName)
-        => await TemplateEngineHelper.GetTemplateDetailsAsync(templateShortName);
+        => await TemplateEngineHelper.GetTemplateDetailsAsync(templateShortName, _logger);
 
     [McpServerTool, Description("Clear the template cache to force reload from disk. Use this after installing or uninstalling templates.")]
     public async Task<string> DotnetTemplateClearCache()
     {
-        await TemplateEngineHelper.ClearCacheAsync();
+        await TemplateEngineHelper.ClearCacheAsync(_logger);
         return "Template cache cleared successfully. Next template query will reload from disk.";
     }
 
@@ -445,6 +452,8 @@ public async Task<string> DotnetNugetLocals(
 
     private async Task<string> ExecuteDotNetCommand(string arguments)
     {
+        _logger.LogDebug("Executing: dotnet {Arguments}", arguments);
+
         var psi = new ProcessStartInfo
         {
             FileName = "dotnet",
@@ -502,6 +511,16 @@ private async Task<string> ExecuteDotNetCommand(string arguments)
         process.BeginErrorReadLine();
         await process.WaitForExitAsync();
 
+        _logger.LogDebug("Command completed with exit code: {ExitCode}", process.ExitCode);
+        if (outputTruncated)
+        {
+            _logger.LogWarning("Output was truncated due to size limit");
+        }
+        if (errorTruncated)
+        {
+            _logger.LogWarning("Error output was truncated due to size limit");
+        }
+
         var result = new StringBuilder();
         if (output.Length > 0) result.AppendLine(output.ToString());
         if (error.Length > 0)

DotNetMcp/TemplateEngineHelper.cs

@@ -1,5 +1,6 @@
 using System.Text;
 using System.Text.Json;
+using Microsoft.Extensions.Logging;
 using Microsoft.TemplateEngine.Abstractions;
 using Microsoft.TemplateEngine.Edge;
 using Microsoft.TemplateEngine.Edge.Settings;
@@ -32,20 +33,27 @@ public class TemplateEngineHelper
     /// Get templates from cache or load them if cache is expired.
     /// Cache expires after 5 minutes to allow for template installations/updates.
     /// </summary>
-    private static async Task<IEnumerable<ITemplateInfo>> GetTemplatesCachedAsync()
+    private static async Task<IEnumerable<ITemplateInfo>> GetTemplatesCachedAsync(ILogger? logger = null)
     {
         await _cacheLock.WaitAsync();
         try
         {
             if (_templatesCache == null || DateTime.UtcNow > _cacheExpiry)
             {
+                logger?.LogDebug("Template cache miss - loading templates from Template Engine");
                 var engineEnvironmentSettings = new EngineEnvironmentSettings(
                     new DefaultTemplateEngineHost("dotnet-mcp", "1.0.0"),
                     virtualizeSettings: true);
 
                 var templatePackageManager = new TemplatePackageManager(engineEnvironmentSettings);
                 _templatesCache = await templatePackageManager.GetTemplatesAsync(default);
                 _cacheExpiry = DateTime.UtcNow.Add(CacheDuration);
+                logger?.LogInformation("Loaded {TemplateCount} templates into cache (expires in {CacheDuration})",
+                    _templatesCache.Count(), CacheDuration);
+            }
+            else
+            {
+                logger?.LogDebug("Template cache hit - returning cached templates");
             }
             return _templatesCache;
         }
@@ -62,13 +70,14 @@ private static async Task<IEnumerable<ITemplateInfo>> GetTemplatesCachedAsync()
     /// This method properly uses async/await to prevent potential deadlocks that could occur
     /// with synchronous Wait() calls on SemaphoreSlim.
     /// </remarks>
-    public static async Task ClearCacheAsync()
+    public static async Task ClearCacheAsync(ILogger? logger = null)
     {
         await _cacheLock.WaitAsync();
         try
         {
             _templatesCache = null;
             _cacheExpiry = DateTime.MinValue;
+            logger?.LogInformation("Template cache cleared");
         }
         finally
         {
@@ -93,12 +102,12 @@ public static void Dispose()
     /// <summary>
     /// Get a list of all installed templates with their metadata.
     /// </summary>
-    public static async Task<string> GetInstalledTemplatesAsync()
+    public static async Task<string> GetInstalledTemplatesAsync(ILogger? logger = null)
     {
         try
         {
             // Get all installed templates from cache
-            var templates = await GetTemplatesCachedAsync();
+            var templates = await GetTemplatesCachedAsync(logger);
 
             if (!templates.Any())
             {
@@ -139,11 +148,11 @@ public static async Task<string> GetInstalledTemplatesAsync()
     /// <summary>
     /// Get detailed information about a specific template.
     /// </summary>
-    public static async Task<string> GetTemplateDetailsAsync(string templateShortName)
+    public static async Task<string> GetTemplateDetailsAsync(string templateShortName, ILogger? logger = null)
     {
         try
         {
-            var templates = await GetTemplatesCachedAsync();
+            var templates = await GetTemplatesCachedAsync(logger);
             var template = templates.FirstOrDefault(t =>
                 t.ShortNameList.Any(sn => sn.Equals(templateShortName, StringComparison.OrdinalIgnoreCase)));
 
@@ -188,11 +197,11 @@ public static async Task<string> GetTemplateDetailsAsync(string templateShortNam
     /// <summary>
     /// Search for templates by name or description.
     /// </summary>
-    public static async Task<string> SearchTemplatesAsync(string searchTerm)
+    public static async Task<string> SearchTemplatesAsync(string searchTerm, ILogger? logger = null)
     {
         try
         {
-            var templates = await GetTemplatesCachedAsync();
+            var templates = await GetTemplatesCachedAsync(logger);
             var matches = templates.Where(t =>
                 t.ShortNameList.Any(sn => sn.Contains(searchTerm, StringComparison.OrdinalIgnoreCase)) ||
                 (t.Name?.Contains(searchTerm, StringComparison.OrdinalIgnoreCase) ?? false) ||
@@ -236,11 +245,11 @@ public static async Task<string> SearchTemplatesAsync(string searchTerm)
     /// <summary>
     /// Validate if a template short name exists.
     /// </summary>
-    public static async Task<bool> ValidateTemplateExistsAsync(string templateShortName)
+    public static async Task<bool> ValidateTemplateExistsAsync(string templateShortName, ILogger? logger = null)
     {
         try
         {
-            var templates = await GetTemplatesCachedAsync();
+            var templates = await GetTemplatesCachedAsync(logger);
             return templates.Any(t =>
                 t.ShortNameList.Any(sn => sn.Equals(templateShortName, StringComparison.OrdinalIgnoreCase)));
         }