diff --git a/CosmosDBShell.Tests/Runtime/DiagnosticLogTests.cs b/CosmosDBShell.Tests/Runtime/DiagnosticLogTests.cs new file mode 100644 index 0000000..e59dcab --- /dev/null +++ b/CosmosDBShell.Tests/Runtime/DiagnosticLogTests.cs @@ -0,0 +1,211 @@ +// ------------------------------------------------------------ +// Copyright (c) Microsoft Corporation. All rights reserved. +// ------------------------------------------------------------ + +using System; +using System.IO; +using System.Linq; +using System.Threading; +using System.Threading.Tasks; + +using Azure.Data.Cosmos.Shell.Core; +using Microsoft.Azure.Cosmos; + +using Xunit; + +namespace CosmosShell.Tests.Runtime; + +public class DiagnosticLogTests : IDisposable +{ + private readonly string path; + + public DiagnosticLogTests() + { + this.path = Path.Combine(Path.GetTempPath(), $"cosmosdbshell-diag-{Guid.NewGuid():N}.log"); + } + + public void Dispose() + { + if (File.Exists(this.path)) + { + File.Delete(this.path); + } + + GC.SuppressFinalize(this); + } + + [Fact] + public void Create_WritesSessionMetadataHeader() + { + using (DiagnosticLog.Create(this.path)) + { + } + + var lines = File.ReadAllLines(this.path); + + Assert.Equal("# CosmosDB Shell Diagnostic Log", lines[0]); + Assert.StartsWith("# Started: ", lines[1]); + Assert.StartsWith("# Machine: ", lines[2]); + Assert.StartsWith("# OS: ", lines[3]); + Assert.StartsWith("# Runtime: ", lines[4]); + Assert.Equal(new string('-', 80), lines[5]); + } + + [Fact] + public void LogConnect_WritesEndpointAndMode() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogConnect(new Uri("https://myaccount.documents.azure.com:443/"), ConnectionMode.Direct); + } + + var line = LastEntry(); + Assert.Matches(@"^\[\d{2}:\d{2}:\d{2}\.\d{3}\] \[CONNECT \] https://myaccount\.documents\.azure\.com:443/ \(mode=Direct\)$", line); + } + + [Fact] + public void LogCommand_WritesCommandText() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogCommand("dir"); + } + + var line = LastEntry(); + Assert.Matches(@"^\[\d{2}:\d{2}:\d{2}\.\d{3}\] \[CMD \] dir$", line); + } + + [Fact] + public void LogResult_Success_WritesOkWithElapsed() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogResult(succeeded: true, elapsedMilliseconds: 333.25, command: "dir"); + } + + var line = LastEntry(); + Assert.Matches(@"^\[\d{2}:\d{2}:\d{2}\.\d{3}\] \[RESULT \] \[OK\] 333\.[23]ms \| dir$", line); + } + + [Fact] + public void LogResult_Failure_WritesFail() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogResult(succeeded: false, elapsedMilliseconds: 2.1, command: "cat nonexistent"); + } + + var line = LastEntry(); + Assert.Contains("[RESULT ] [FAIL] 2.1ms | cat nonexistent", line); + } + + [Fact] + public void LogError_WritesExceptionTypeAndMessage() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogError("cat nonexistent", new InvalidOperationException("Item not found")); + } + + var line = LastEntry(); + Assert.Contains("[ERROR ] cat nonexistent -> InvalidOperationException: Item not found", line); + } + + [Fact] + public void LogCommand_FlattensMultiLineCommand() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogCommand("line one\r\nline two"); + } + + var line = LastEntry(); + Assert.EndsWith("[CMD ] line one line two", line); + } + + [Fact] + public void LogCommand_RedactsAccountKey() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogCommand("connect \"AccountEndpoint=https://acc.documents.azure.com:443/;AccountKey=SuperSecretKey123==;\""); + } + + var line = LastEntry(); + Assert.DoesNotContain("SuperSecretKey123", line); + Assert.Contains("AccountKey=***", line); + Assert.Contains("AccountEndpoint=https://acc.documents.azure.com:443/", line); + } + + [Fact] + public void LogCancelled_WritesCancelledStatus() + { + using (var log = DiagnosticLog.Create(this.path)) + { + log.LogResult(succeeded: true, elapsedMilliseconds: 5.0, command: "noop"); + log.LogCancelled(elapsedMilliseconds: 12.5, command: "long-running"); + } + + var line = LastEntry(); + Assert.Matches(@"^\[\d{2}:\d{2}:\d{2}\.\d{3}\] \[RESULT \] \[CANCELLED\] 12\.5ms \| long-running$", line); + } + + private string LastEntry() + { + return File.ReadAllLines(this.path).Last(l => l.StartsWith('[')); + } +} + +public class DiagnosticLogInterpreterTests : IDisposable +{ + private readonly string path; + + public DiagnosticLogInterpreterTests() + { + this.path = Path.Combine(Path.GetTempPath(), $"cosmosdbshell-diag-{Guid.NewGuid():N}.log"); + } + + public void Dispose() + { + if (File.Exists(this.path)) + { + File.Delete(this.path); + } + + GC.SuppressFinalize(this); + } + + [Fact] + public async Task ExecuteCommandAsync_WhenDiagnosticsEnabled_WritesCommandAndResult() + { + var interpreter = new ShellInterpreter(); + interpreter.EnableDiagnostics(this.path); + + await interpreter.ExecuteCommandAsync("$x = 1", CancellationToken.None); + interpreter.Dispose(); + + var entries = File.ReadAllLines(this.path).Where(l => l.StartsWith('[')).ToArray(); + Assert.Contains(entries, l => l.Contains("[CMD ] $x = 1")); + Assert.Contains(entries, l => l.Contains("[RESULT ] [OK]") && l.Contains("$x = 1")); + } + + [Fact] + public async Task ExecuteCommandAsync_WhenCanceled_DoesNotLogResultAsOk() + { + var interpreter = new ShellInterpreter(); + interpreter.EnableDiagnostics(this.path); + + using var cts = new CancellationTokenSource(); + cts.Cancel(); + + await interpreter.ExecuteCommandAsync("$x = 1", cts.Token); + interpreter.Dispose(); + + var entries = File.ReadAllLines(this.path).Where(l => l.StartsWith('[')).ToArray(); + var resultEntries = entries.Where(l => l.Contains("[RESULT ]")).ToArray(); + Assert.NotEmpty(resultEntries); + Assert.All(resultEntries, l => Assert.DoesNotContain("[OK]", l)); + Assert.Contains(resultEntries, l => l.Contains("[CANCELLED]")); + } +} + diff --git a/CosmosDBShell/Azure.Data.Cosmos.Shell.Core/DiagnosticLog.cs b/CosmosDBShell/Azure.Data.Cosmos.Shell.Core/DiagnosticLog.cs new file mode 100644 index 0000000..56dbd09 --- /dev/null +++ b/CosmosDBShell/Azure.Data.Cosmos.Shell.Core/DiagnosticLog.cs @@ -0,0 +1,202 @@ +// ------------------------------------------------------------ +// Copyright (c) Microsoft Corporation. All rights reserved. +// ------------------------------------------------------------ + +namespace Azure.Data.Cosmos.Shell.Core; + +using System.Globalization; +using System.Text.RegularExpressions; +using Microsoft.Azure.Cosmos; + +/// +/// Writes timestamped diagnostic entries to a log file so users can capture shell +/// activity (command execution, timing, errors, and connection events) for +/// troubleshooting, performance analysis, and auditing. Enabled via the +/// --diagnostics CLI option. All writes are serialized and IO failures are +/// swallowed so diagnostics never disrupt the interactive session. +/// +internal sealed class DiagnosticLog : IDisposable +{ + private const int TagWidth = 8; + + private static readonly Regex AccountKeyPattern = new( + "(?i)(AccountKey\\s*=\\s*)[^;\\s\"']+", + RegexOptions.Compiled); + + private readonly object gate = new(); + + private StreamWriter? writer; + + private bool disposed; + + private DiagnosticLog(string path, StreamWriter writer) + { + this.Path = path; + this.writer = writer; + } + + /// + /// Gets the resolved path of the diagnostic log file. + /// + public string Path { get; } + + /// + /// Creates a diagnostic log at and writes the session + /// metadata header. + /// + /// The fully-qualified path of the log file to create. + /// The initialized . + public static DiagnosticLog Create(string path) + { + var directory = System.IO.Path.GetDirectoryName(path); + if (!string.IsNullOrEmpty(directory)) + { + Directory.CreateDirectory(directory); + } + + var writer = new StreamWriter(new FileStream(path, FileMode.Create, FileAccess.Write, FileShare.Read)) + { + AutoFlush = true, + }; + + var log = new DiagnosticLog(path, writer); + log.WriteHeader(); + return log; + } + + /// + /// Records a successful connection to a Cosmos DB account. + /// + /// The account endpoint that was connected to. + /// The connection mode negotiated for the client. + public void LogConnect(Uri endpoint, ConnectionMode mode) + { + var endpointText = endpoint.GetComponents( + UriComponents.AbsoluteUri | UriComponents.StrongPort, + UriFormat.UriEscaped); + this.WriteLine("CONNECT", $"{endpointText} (mode={mode})"); + } + + /// + /// Records that a command is about to be executed. + /// + /// The command text. + public void LogCommand(string command) + { + this.WriteLine("CMD", Flatten(command)); + } + + /// + /// Records the outcome and elapsed time of a command. + /// + /// true when the command completed without error. + /// The wall-clock execution time in milliseconds. + /// The command text. + public void LogResult(bool succeeded, double elapsedMilliseconds, string command) + { + var status = succeeded ? "[OK]" : "[FAIL]"; + var elapsed = elapsedMilliseconds.ToString("0.0", CultureInfo.InvariantCulture); + this.WriteLine("RESULT", $"{status} {elapsed}ms | {Flatten(command)}"); + } + + /// + /// Records that a command was canceled before it completed. + /// + /// The wall-clock execution time in milliseconds. + /// The command text. + public void LogCancelled(double elapsedMilliseconds, string command) + { + var elapsed = elapsedMilliseconds.ToString("0.0", CultureInfo.InvariantCulture); + this.WriteLine("RESULT", $"[CANCELLED] {elapsed}ms | {Flatten(command)}"); + } + + /// + /// Records the exception raised by a failed command. + /// + /// The command text. + /// The exception that was raised. + public void LogError(string command, Exception exception) + { + this.WriteLine("ERROR", $"{Flatten(command)} -> {exception.GetType().Name}: {Flatten(exception.Message)}"); + } + + /// + public void Dispose() + { + lock (this.gate) + { + if (this.disposed) + { + return; + } + + this.disposed = true; + try + { + this.writer?.Dispose(); + } + catch (IOException) + { + } + finally + { + this.writer = null; + } + } + } + + private static string Flatten(string value) + { + if (string.IsNullOrEmpty(value)) + { + return string.Empty; + } + + var redacted = AccountKeyPattern.Replace(value, "$1***"); + return redacted.Replace("\r\n", " ").Replace('\r', ' ').Replace('\n', ' ').Trim(); + } + + private void WriteHeader() + { + lock (this.gate) + { + if (this.writer is null) + { + return; + } + + try + { + this.writer.WriteLine("# CosmosDB Shell Diagnostic Log"); + this.writer.WriteLine($"# Started: {DateTimeOffset.Now:O}"); + this.writer.WriteLine($"# Machine: {Environment.MachineName}"); + this.writer.WriteLine($"# OS: {Environment.OSVersion.VersionString}"); + this.writer.WriteLine($"# Runtime: {Environment.Version}"); + this.writer.WriteLine(new string('-', 80)); + } + catch (IOException) + { + } + } + } + + private void WriteLine(string tag, string message) + { + lock (this.gate) + { + if (this.writer is null) + { + return; + } + + var timestamp = DateTime.Now.ToString("HH:mm:ss.fff", CultureInfo.InvariantCulture); + try + { + this.writer.WriteLine($"[{timestamp}] [{tag.PadRight(TagWidth)}] {message}"); + } + catch (IOException) + { + } + } + } +} diff --git a/CosmosDBShell/Azure.Data.Cosmos.Shell.Core/ShellInterpreter.cs b/CosmosDBShell/Azure.Data.Cosmos.Shell.Core/ShellInterpreter.cs index 4dedde9..7b3b84c 100644 --- a/CosmosDBShell/Azure.Data.Cosmos.Shell.Core/ShellInterpreter.cs +++ b/CosmosDBShell/Azure.Data.Cosmos.Shell.Core/ShellInterpreter.cs @@ -161,6 +161,8 @@ internal static char CSVSeparator internal Program.CosmosShellOptions? Options { get; set; } + internal DiagnosticLog? Diagnostics { get; private set; } + internal int? McpPort { get; set; } internal Queue VariableContainers { get; } = new(); @@ -275,6 +277,11 @@ public async Task ExecuteCommandAsync(string command, Cancellation var savedErrOut = this.ErrOutRedirect; var savedAppendErr = this.AppendErrRedirection; + var diagnostics = this.Diagnostics; + var stopwatch = diagnostics is null ? null : System.Diagnostics.Stopwatch.StartNew(); + diagnostics?.LogCommand(command); + CommandState? result = null; + try { try @@ -283,33 +290,39 @@ public async Task ExecuteCommandAsync(string command, Cancellation } catch (OperationCanceledException) when (token.IsCancellationRequested) { - return new CommandState(); + result = new CommandState(); + return result; } catch (TaskCanceledException e) { var shellException = new ShellException(CommandException.GetDisplayMessage(e), e); this.ReportExecutionError(shellException, command); - return new ErrorCommandState(shellException); + result = new ErrorCommandState(shellException); + return result; } catch (Exception e) { this.ReportExecutionError(e, command); var inner = e is PositionalException pe ? (pe.InnerException ?? pe) : e; - return new ErrorCommandState(inner); + result = new ErrorCommandState(inner); + return result; } if (token.IsCancellationRequested) { - return state; + result = state; + return result; } if (state is ParserErrorCommandState parserErrorState) { this.ReportParserErrors(parserErrorState.Errors, command); - return state; + result = state; + return result; } - return this.PrintState(state); + result = this.PrintState(state); + return result; } finally { @@ -317,6 +330,25 @@ public async Task ExecuteCommandAsync(string command, Cancellation this.AppendOutRedirection = savedAppendOut; this.ErrOutRedirect = savedErrOut; this.AppendErrRedirection = savedAppendErr; + + if (diagnostics is not null && stopwatch is not null) + { + stopwatch.Stop(); + if (token.IsCancellationRequested) + { + diagnostics.LogCancelled(stopwatch.Elapsed.TotalMilliseconds, command); + } + else + { + var succeeded = !(result?.IsError ?? true); + if (!succeeded && result is ErrorCommandState errorState) + { + diagnostics.LogError(command, errorState.Exception); + } + + diagnostics.LogResult(succeeded, stopwatch.Elapsed.TotalMilliseconds, command); + } + } } } @@ -1106,6 +1138,35 @@ internal void Connect(CosmosClient client, ArmCosmosContext? armContext = null) this.State = new ConnectedState(client, armContext); CosmosCompleteCommand.ClearDatabases(); CosmosCompleteCommand.ClearContainers(); + this.Diagnostics?.LogConnect(client.Endpoint, client.ClientOptions.ConnectionMode); + } + + /// + /// Enables diagnostic logging for the session, writing entries to + /// when supplied, or to a timestamped file in the + /// shell configuration directory otherwise. + /// + /// An optional custom log file path. + internal void EnableDiagnostics(string? path) + { + if (this.Diagnostics is not null) + { + return; + } + + var resolvedPath = string.IsNullOrWhiteSpace(path) + ? Path.Combine(this.cfgPath, $"diagnostics-{DateTime.Now:yyyyMMdd-HHmmss}.log") + : Path.GetFullPath(path); + + try + { + this.Diagnostics = DiagnosticLog.Create(resolvedPath); + WriteLine(MessageService.GetArgsString("diagnostics-enabled", "path", this.Diagnostics.Path)); + } + catch (Exception ex) when (ex is IOException or UnauthorizedAccessException or ArgumentException or NotSupportedException) + { + WriteLine(MessageService.GetArgsString("diagnostics-error-create", "path", resolvedPath, "message", ex.Message)); + } } private void AttachArmContext(CosmosClient client, ArmCosmosContext armContext) @@ -1298,6 +1359,7 @@ protected virtual void Dispose(bool disposing) currentTokenSource?.Dispose(); this.editorCancelTokenSource?.Dispose(); this.State?.Dispose(); + this.Diagnostics?.Dispose(); } this.disposedValue = true; diff --git a/CosmosDBShell/Program.cs b/CosmosDBShell/Program.cs index 5ed9eab..ea630bb 100644 --- a/CosmosDBShell/Program.cs +++ b/CosmosDBShell/Program.cs @@ -108,6 +108,16 @@ public static async Task Main(string[] args) o.McpPort = mcpValue ?? DefaultMcpPort; } + // --diagnostics supports an optional value: when present without a path, + // logging is written to a timestamped file in the config directory. + var diagnosticsResult = parseResult.FindResultFor(optionMap.Diagnostics); + if (diagnosticsResult is not null) + { + o.EnableDiagnostics = true; + var diagnosticsValue = parseResult.GetValueForOption(optionMap.Diagnostics); + o.DiagnosticsPath = string.IsNullOrWhiteSpace(diagnosticsValue) ? null : diagnosticsValue; + } + if (o.StartLspServer) { // Already handled above, but keep for completeness @@ -149,6 +159,13 @@ public static async Task Main(string[] args) ShellInterpreter.Instance.Options = o; + // Enable diagnostic logging before connecting so the startup --connect + // event is captured in the log. + if (o.EnableDiagnostics) + { + ShellInterpreter.Instance.EnableDiagnostics(o.DiagnosticsPath); + } + if (o.ConnectionString != null) { using var connectTokenSource = ShellInterpreter.UserCancellationTokenSource; @@ -450,6 +467,10 @@ private static (RootCommand Command, OptionMap Map) BuildRootCommand() }; var verbose = new Option("--verbose", MessageService.GetString("help-Verbose")); var theme = new Option("--theme", MessageService.GetString("help-Theme")); + var diagnostics = new Option("--diagnostics", MessageService.GetString("help-Diagnostics")) + { + Arity = ArgumentArity.ZeroOrOne, + }; var root = new RootCommand("Cosmos DB Shell") { @@ -471,6 +492,7 @@ private static (RootCommand Command, OptionMap Map) BuildRootCommand() lspStdio, verbose, theme, + diagnostics, }; var map = new OptionMap( @@ -491,7 +513,8 @@ private static (RootCommand Command, OptionMap Map) BuildRootCommand() startLspServer, lspStdio, verbose, - theme); + theme, + diagnostics); return (root, map); } @@ -517,6 +540,7 @@ private static string BuildHelpText() [map.ConnectResourceGroup] = "", [map.McpPort] = "[]", [map.Theme] = "", + [map.Diagnostics] = "[]", }; var rows = new List<(string Label, string? Description)>(); @@ -620,7 +644,8 @@ private sealed record OptionMap( Option StartLspServer, Option LspStdio, Option Verbose, - Option Theme); + Option Theme, + Option Diagnostics); /// /// Maps the most common System.CommandLine parse error messages @@ -698,5 +723,9 @@ public class CosmosShellOptions public bool Verbose { get; set; } public string? Theme { get; set; } + + public bool EnableDiagnostics { get; set; } + + public string? DiagnosticsPath { get; set; } } } diff --git a/CosmosDBShell/lang/en.ftl b/CosmosDBShell/lang/en.ftl index f1bc7e5..00af2a3 100644 --- a/CosmosDBShell/lang/en.ftl +++ b/CosmosDBShell/lang/en.ftl @@ -622,7 +622,10 @@ help-EnableLspServer = Enable Language Server Protocol (LSP) server for editor i help-McpPort = Enable MCP HTTP server. Optionally specify a port with --mcp ; default is 6128. help-Verbose = Print full exception details instead of only the message. help-Theme = Color theme profile to apply at startup. Falls back to the COSMOSDB_SHELL_THEME environment variable. +help-Diagnostics = Write timestamped diagnostic logs to a file. Optionally specify a path with --diagnostics ; defaults to a timestamped file in the shell configuration directory. mcp-error-invalid-port = Error: --mcp port must be greater than 0. +diagnostics-enabled = Writing diagnostic log to { $path }. +diagnostics-error-create = Error: could not create diagnostic log at '{ $path }': { $message } warning-unknown-theme = Unknown theme '{ $name }'. Available themes: { $themes }. Falling back to default. diff --git a/README.md b/README.md index 0937509..e6fd900 100644 --- a/README.md +++ b/README.md @@ -130,6 +130,7 @@ Packaging runs produce preview versions in the form `1.0.-preview.` | `--connect-subscription ` | Azure subscription ID for ARM database and container operations | | `--connect-resource-group ` | Azure resource group name for ARM database and container operations | | `--mcp [port]` | Enable MCP server on the given port, or `6128` by default | +| `--diagnostics [path]` | Write timestamped diagnostic logs to a file, or to a timestamped file in the config directory by default | | `--verbose` | Print full exception details | | `--color-system ` | Colors: 0=off, 1=standard, 2=truecolor (alias: `--cs`) | | `--theme ` | Color theme profile to apply at startup (`default`, `light`, `dark`, `monochrome`). Falls back to `COSMOSDB_SHELL_THEME`. | diff --git a/docs/navigation.md b/docs/navigation.md index de33b3d..aca7714 100644 --- a/docs/navigation.md +++ b/docs/navigation.md @@ -269,6 +269,7 @@ Start the shell with options to customize behavior: | `--connect-subscription ` | Azure subscription ID for ARM database and container operations at startup | | `--connect-resource-group ` | Azure resource group name for ARM database and container operations at startup | | `--mcp [port]` | Enable MCP (Model Context Protocol) server on the given port, or `6128` by default | +| `--diagnostics [path]` | Write timestamped diagnostic logs (commands, timing, errors, connection events) to a file, or to a timestamped file in the config directory by default | | `--color-system ` | Color scheme: 0=off, 1=standard, 2=truecolor (alias: `--cs`) | | `--clear-history` | Clear command history on start | | `--help` | Show usage information | @@ -300,4 +301,10 @@ cosmosdbshell --mcp # Start with MCP server enabled on a custom port cosmosdbshell --mcp 5050 + +# Capture a diagnostic log to the default location in the config directory +cosmosdbshell --diagnostics + +# Capture a diagnostic log to a custom file +cosmosdbshell --diagnostics mylog.log ```