// Copyright 2012-2025 The NATS Authors // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at // // http://www.apache.org/licenses/LICENSE-2.0 // // Unless required by applicable law or agreed to in writing, software // distributed under the License is distributed on an "AS IS" BASIS, // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. // See the License for the specific language governing permissions and // limitations under the License. using Shouldly; using System.Reflection; using ZB.MOM.NatsNet.Server; using ZB.MOM.NatsNet.Server.Internal; namespace ZB.MOM.NatsNet.Server.Tests.Internal; /// /// Tests for server logging trace sanitization (RemovePassFromTrace, RemoveAuthTokenFromTrace). /// Mirrors server/log_test.go — TestNoPasswordsFromConnectTrace, TestRemovePassFromTrace, /// TestRemoveAuthTokenFromTrace. /// public class ServerLoggerTests { // --------------------------------------------------------------------------- // T:2020 — TestNoPasswordsFromConnectTrace // --------------------------------------------------------------------------- /// /// Mirrors TestNoPasswordsFromConnectTrace. /// Verifies that a CONNECT trace with a password or auth_token does not /// expose the secret value after sanitization. /// [Fact] // T:2020 public void NoPasswordsFromConnectTrace_ShouldSucceed() { const string connectWithPass = """CONNECT {"verbose":false,"pedantic":false,"user":"derek","pass":"s3cr3t","tls_required":false}"""; const string connectWithToken = """CONNECT {"verbose":false,"auth_token":"secret-token","tls_required":false}"""; ServerLogging.RemovePassFromTrace(connectWithPass).ShouldNotContain("s3cr3t"); ServerLogging.RemoveAuthTokenFromTrace(connectWithToken).ShouldNotContain("secret-token"); } // --------------------------------------------------------------------------- // T:2021 — TestRemovePassFromTrace // --------------------------------------------------------------------------- /// /// Mirrors TestRemovePassFromTrace — covers all test vectors from log_test.go. /// Each case verifies that RemovePassFromTrace redacts the first pass/password value /// with [REDACTED] while leaving other fields intact. /// [Theory] // T:2021 [InlineData( "user and pass", "CONNECT {\"user\":\"derek\",\"pass\":\"s3cr3t\"}\r\n", "CONNECT {\"user\":\"derek\",\"pass\":\"[REDACTED]\"}\r\n")] [InlineData( "user and pass extra space", "CONNECT {\"user\":\"derek\",\"pass\": \"s3cr3t\"}\r\n", "CONNECT {\"user\":\"derek\",\"pass\": \"[REDACTED]\"}\r\n")] [InlineData( "user and pass is empty", "CONNECT {\"user\":\"derek\",\"pass\":\"\"}\r\n", "CONNECT {\"user\":\"derek\",\"pass\":\"[REDACTED]\"}\r\n")] [InlineData( "user and pass is empty whitespace", "CONNECT {\"user\":\"derek\",\"pass\":\" \"}\r\n", "CONNECT {\"user\":\"derek\",\"pass\":\"[REDACTED]\"}\r\n")] [InlineData( "only pass", "CONNECT {\"pass\":\"s3cr3t\",}\r\n", "CONNECT {\"pass\":\"[REDACTED]\",}\r\n")] [InlineData( "complete connect", "CONNECT {\"echo\":true,\"verbose\":false,\"pedantic\":false,\"user\":\"foo\",\"pass\":\"s3cr3t\",\"tls_required\":false,\"name\":\"APM7JU94z77YzP6WTBEiuw\"}\r\n", "CONNECT {\"echo\":true,\"verbose\":false,\"pedantic\":false,\"user\":\"foo\",\"pass\":\"[REDACTED]\",\"tls_required\":false,\"name\":\"APM7JU94z77YzP6WTBEiuw\"}\r\n")] [InlineData( "user and pass are filtered", "CONNECT {\"user\":\"s3cr3t\",\"pass\":\"s3cr3t\"}\r\n", "CONNECT {\"user\":\"s3cr3t\",\"pass\":\"[REDACTED]\"}\r\n")] [InlineData( "single long password", "CONNECT {\"pass\":\"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA\"}\r\n", "CONNECT {\"pass\":\"[REDACTED]\"}\r\n")] public void RemovePassFromTrace_ShouldSucceed(string name, string input, string expected) { _ = name; // used for test display only ServerLogging.RemovePassFromTrace(input).ShouldBe(expected); } // --------------------------------------------------------------------------- // T:2022 — TestRemoveAuthTokenFromTrace // --------------------------------------------------------------------------- /// /// Mirrors TestRemoveAuthTokenFromTrace — covers representative test vectors /// from log_test.go. Each case verifies that RemoveAuthTokenFromTrace redacts /// the first auth_token value with [REDACTED]. /// [Theory] // T:2022 [InlineData( "user and auth_token", "CONNECT {\"user\":\"derek\",\"auth_token\":\"s3cr3t\"}\r\n", "CONNECT {\"user\":\"derek\",\"auth_token\":\"[REDACTED]\"}\r\n")] [InlineData( "user and auth_token extra space", "CONNECT {\"user\":\"derek\",\"auth_token\": \"s3cr3t\"}\r\n", "CONNECT {\"user\":\"derek\",\"auth_token\": \"[REDACTED]\"}\r\n")] [InlineData( "user and auth_token is empty", "CONNECT {\"user\":\"derek\",\"auth_token\":\"\"}\r\n", "CONNECT {\"user\":\"derek\",\"auth_token\":\"[REDACTED]\"}\r\n")] [InlineData( "only auth_token", "CONNECT {\"auth_token\":\"s3cr3t\",}\r\n", "CONNECT {\"auth_token\":\"[REDACTED]\",}\r\n")] [InlineData( "complete connect", "CONNECT {\"echo\":true,\"verbose\":false,\"pedantic\":false,\"auth_token\":\"s3cr3t\",\"tls_required\":false,\"name\":\"APM7JU94z77YzP6WTBEiuw\"}\r\n", "CONNECT {\"echo\":true,\"verbose\":false,\"pedantic\":false,\"auth_token\":\"[REDACTED]\",\"tls_required\":false,\"name\":\"APM7JU94z77YzP6WTBEiuw\"}\r\n")] [InlineData( "user and token are filtered", "CONNECT {\"user\":\"s3cr3t\",\"auth_token\":\"s3cr3t\"}\r\n", "CONNECT {\"user\":\"s3cr3t\",\"auth_token\":\"[REDACTED]\"}\r\n")] [InlineData( "single long token", "CONNECT {\"auth_token\":\"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA\"}\r\n", "CONNECT {\"auth_token\":\"[REDACTED]\"}\r\n")] public void RemoveAuthTokenFromTrace_ShouldSucceed(string name, string input, string expected) { _ = name; // used for test display only ServerLogging.RemoveAuthTokenFromTrace(input).ShouldBe(expected); } [Fact] public void SetLogger_SetLoggerV2AndConfigureLogger_ShouldApplyExpectedSemantics() { var (server, err) = NatsServer.NewServer(new ServerOptions()); err.ShouldBeNull(); server.ShouldNotBeNull(); var setLogger = GetRequiredServerMethod("SetLogger", typeof(INatsLogger), typeof(bool), typeof(bool)); var setLoggerV2 = GetRequiredServerMethod("SetLoggerV2", typeof(INatsLogger), typeof(bool), typeof(bool), typeof(bool)); var configureLogger = GetRequiredServerMethod("ConfigureLogger"); var executeLogCall = GetRequiredServerMethod("ExecuteLogCall", typeof(Action)); var first = new CapturingLogger(); setLogger.Invoke(server, [first, true, true]); GetPrivateIntField(server!, "_debugEnabled").ShouldBe(1); GetPrivateIntField(server!, "_traceEnabled").ShouldBe(1); GetPrivateIntField(server!, "_traceSysAcc").ShouldBe(0); var second = new CapturingLogger(); setLoggerV2.Invoke(server, [second, false, false, true]); first.Disposed.ShouldBeTrue(); GetPrivateIntField(server!, "_debugEnabled").ShouldBe(0); GetPrivateIntField(server!, "_traceEnabled").ShouldBe(0); GetPrivateIntField(server!, "_traceSysAcc").ShouldBe(1); var noLogOptions = server!.Options; noLogOptions.NoLog = true; configureLogger.Invoke(server, null); InvokeNoticef(server, "no-log should keep existing logger"); second.Messages.ShouldContain(msg => msg.Contains("no-log should keep existing logger", StringComparison.Ordinal)); var calls = 0; executeLogCall.Invoke(server, [(Action)(_ => calls++)]); calls.ShouldBe(1); } [Fact] public void ReOpenLogFile_ByLoggerMode_ShouldMatchExpectedBehavior() { var (server, err) = NatsServer.NewServer(new ServerOptions()); err.ShouldBeNull(); server.ShouldNotBeNull(); var setLogger = GetRequiredServerMethod("SetLogger", typeof(INatsLogger), typeof(bool), typeof(bool)); var configureLogger = GetRequiredServerMethod("ConfigureLogger"); var reOpenLogFile = GetRequiredServerMethod("ReOpenLogFile"); var executeLogCall = GetRequiredServerMethod("ExecuteLogCall", typeof(Action)); // Nil logger path: executeLogCall should no-op. var called = false; executeLogCall.Invoke(server, [(Action)(_ => called = true)]); called.ShouldBeFalse(); // Non-file logger path. var memoryLogger = new CapturingLogger(); setLogger.Invoke(server, [memoryLogger, false, false]); reOpenLogFile.Invoke(server, null); memoryLogger.Messages.ShouldContain(m => m.Contains("not a file logger", StringComparison.Ordinal)); // File logger path. var logFile = Path.Combine(Path.GetTempPath(), $"{Guid.NewGuid():N}.log"); var opts = server!.Options; opts.LogFile = logFile; opts.NoLog = false; opts.Debug = false; opts.Trace = false; opts.Logtime = false; configureLogger.Invoke(server, null); InvokeNoticef(server, "message-before-reopen"); reOpenLogFile.Invoke(server, null); InvokeNoticef(server, "message-after-reopen"); File.Exists(logFile).ShouldBeTrue(); var content = File.ReadAllText(logFile); content.ShouldContain("File log re-opened"); content.ShouldContain("message-after-reopen"); } [Fact] public void ErrorsVariants_ShouldUseExpectedFormatting() { var (server, err) = NatsServer.NewServer(new ServerOptions()); err.ShouldBeNull(); server.ShouldNotBeNull(); var setLogger = GetRequiredServerMethod("SetLogger", typeof(INatsLogger), typeof(bool), typeof(bool)); var errors = GetRequiredServerMethod("Errors", typeof(object), typeof(Exception)); var errorc = GetRequiredServerMethod("Errorc", typeof(string), typeof(Exception)); var errorsc = GetRequiredServerMethod("Errorsc", typeof(object), typeof(string), typeof(Exception)); var logger = new CapturingLogger(); setLogger.Invoke(server, [logger, false, false]); var wrapped = ErrorContextHelper.NewErrorCtx(new Exception("connection reset"), "leaf reconnect"); errors.Invoke(server, ["client", wrapped]); errorc.Invoke(server, ["tls", wrapped]); errorsc.Invoke(server, ["route", "cluster", wrapped]); logger.Messages.Count.ShouldBe(3); logger.Messages[0].ShouldContain("client - connection reset: leaf reconnect"); logger.Messages[1].ShouldContain("tls: connection reset: leaf reconnect"); logger.Messages[2].ShouldContain("route - cluster: connection reset: leaf reconnect"); } [Fact] public void RateLimitHelpers_ShouldRespectDedupeSemanticsAndDebugFlag() { var (server, err) = NatsServer.NewServer(new ServerOptions()); err.ShouldBeNull(); server.ShouldNotBeNull(); var setLogger = GetRequiredServerMethod("SetLogger", typeof(INatsLogger), typeof(bool), typeof(bool)); var rateLimitFormatWarnf = GetRequiredServerMethod("RateLimitFormatWarnf", typeof(string), typeof(object[])); var rateLimitWarnf = GetRequiredServerMethod("RateLimitWarnf", typeof(string), typeof(object[])); var rateLimitDebugf = GetRequiredServerMethod("RateLimitDebugf", typeof(string), typeof(object[])); var logger = new CapturingLogger(); setLogger.Invoke(server, [logger, false, false]); // Dedupe by format string (same format, different args => single warning). rateLimitFormatWarnf.Invoke(server, ["format {0}", new object[] { "one" }]); rateLimitFormatWarnf.Invoke(server, ["format {0}", new object[] { "two" }]); rateLimitFormatWarnf.Invoke(server, ["other {0}", new object[] { "three" }]); logger.Messages.Count.ShouldBe(2); logger.Messages.ShouldContain("format one"); logger.Messages.ShouldContain("other three"); // Dedupe by rendered statement. logger.Messages.Clear(); rateLimitWarnf.Invoke(server, ["warn {0}", new object[] { "same" }]); rateLimitWarnf.Invoke(server, ["warn {0}", new object[] { "same" }]); rateLimitWarnf.Invoke(server, ["warn {0}", new object[] { "other" }]); logger.Messages.Count.ShouldBe(2); logger.Messages.ShouldContain("warn same"); logger.Messages.ShouldContain("warn other"); // Debug dedupe + debug-flag gating. logger.Messages.Clear(); rateLimitDebugf.Invoke(server, ["debug {0}", new object[] { "suppressed" }]); logger.Messages.ShouldBeEmpty(); setLogger.Invoke(server, [logger, true, false]); rateLimitDebugf.Invoke(server, ["debug {0}", new object[] { "visible" }]); rateLimitDebugf.Invoke(server, ["debug {0}", new object[] { "visible" }]); logger.Messages.Count.ShouldBe(1); logger.Messages[0].ShouldContain("debug visible"); } private static int GetPrivateIntField(object target, string fieldName) { var field = target.GetType().GetField(fieldName, BindingFlags.Instance | BindingFlags.NonPublic); field.ShouldNotBeNull(); return (int)field!.GetValue(target)!; } private static MethodInfo GetRequiredServerMethod(string name, params Type[] parameterTypes) { var method = typeof(NatsServer).GetMethod( name, BindingFlags.Instance | BindingFlags.Public | BindingFlags.NonPublic, binder: null, types: parameterTypes, modifiers: null); method.ShouldNotBeNull($"{name} should exist on NatsServer"); return method!; } private static void InvokeNoticef(NatsServer server, string message) { var noticeMethod = typeof(NatsServer).GetMethod( "Noticef", BindingFlags.Instance | BindingFlags.NonPublic); noticeMethod.ShouldNotBeNull(); noticeMethod!.Invoke(server, ["{0}", new object?[] { message }]); } private sealed class CapturingLogger : INatsLogger, IDisposable { public List Messages { get; } = []; public bool Disposed { get; private set; } public void Noticef(string format, params object[] args) => Messages.Add(string.Format(format, args)); public void Warnf(string format, params object[] args) => Messages.Add(string.Format(format, args)); public void Fatalf(string format, params object[] args) => Messages.Add(string.Format(format, args)); public void Errorf(string format, params object[] args) => Messages.Add(string.Format(format, args)); public void Debugf(string format, params object[] args) => Messages.Add(string.Format(format, args)); public void Tracef(string format, params object[] args) => Messages.Add(string.Format(format, args)); public void Dispose() => Disposed = true; } }