From b79e7aafe94d570876efa771eb1169dcfbda2444 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Sat, 28 Feb 2026 07:56:32 -0500 Subject: [PATCH] feat(batch4-task2): implement core logger wiring features --- .../Internal/NatsLogger.cs | 2 + .../NatsServer.Logging.cs | 367 ++++++++++++++++++ .../Internal/ServerLoggerTests.cs | 128 ++++++ porting.db | Bin 6365184 -> 6365184 bytes 4 files changed, 497 insertions(+) create mode 100644 dotnet/src/ZB.MOM.NatsNet.Server/NatsServer.Logging.cs diff --git a/dotnet/src/ZB.MOM.NatsNet.Server/Internal/NatsLogger.cs b/dotnet/src/ZB.MOM.NatsNet.Server/Internal/NatsLogger.cs index 04ca274..b78a568 100644 --- a/dotnet/src/ZB.MOM.NatsNet.Server/Internal/NatsLogger.cs +++ b/dotnet/src/ZB.MOM.NatsNet.Server/Internal/NatsLogger.cs @@ -215,6 +215,8 @@ public sealed class MicrosoftLoggerAdapter : INatsLogger public MicrosoftLoggerAdapter(ILogger logger) => _logger = logger; + internal ILogger UnderlyingLogger => _logger; + public void Noticef(string format, params object[] args) => _logger.LogInformation(format, args); diff --git a/dotnet/src/ZB.MOM.NatsNet.Server/NatsServer.Logging.cs b/dotnet/src/ZB.MOM.NatsNet.Server/NatsServer.Logging.cs new file mode 100644 index 0000000..fb76d92 --- /dev/null +++ b/dotnet/src/ZB.MOM.NatsNet.Server/NatsServer.Logging.cs @@ -0,0 +1,367 @@ +// Copyright 2012-2026 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. +// +// Adapted from server/log.go in the NATS server Go source. + +using System.Text; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; +using ZB.MOM.NatsNet.Server.Internal; + +namespace ZB.MOM.NatsNet.Server; + +public sealed partial class NatsServer +{ + private readonly object _loggingLock = new(); + private INatsLogger? _natsLogger; + + /// + /// Configures and sets the server logger. + /// Mirrors Go Server.ConfigureLogger(). + /// + public void ConfigureLogger() + { + var opts = GetOpts(); + if (opts.NoLog) + { + return; + } + + var syslog = opts.Syslog; + if (ServiceManager.IsWindowsService() && string.IsNullOrEmpty(opts.LogFile)) + { + syslog = true; + } + + if (!string.IsNullOrEmpty(opts.LogFile)) + { + var fileLogger = new FileNatsLogger(opts.LogFile, opts.Logtime, opts.LogtimeUtc); + if (opts.LogSizeLimit > 0) + { + fileLogger.SetSizeLimit(opts.LogSizeLimit); + } + + if (opts.LogMaxFiles > 0) + { + var maxFiles = opts.LogMaxFiles > int.MaxValue ? 0 : (int)opts.LogMaxFiles; + fileLogger.SetMaxNumFiles(maxFiles); + } + + SetLoggerV2(fileLogger, opts.Debug, opts.Trace, opts.TraceVerbose); + return; + } + + // Syslog/remote-syslog-specific sinks are not yet ported. + // Keep parity with Go option precedence and wire to the current ILogger backend. + if (!string.IsNullOrEmpty(opts.RemoteSyslog) || syslog) + { + SetLoggerV2(new MicrosoftLoggerAdapter(_logger), opts.Debug, opts.Trace, opts.TraceVerbose); + return; + } + + SetLoggerV2(new MicrosoftLoggerAdapter(_logger), opts.Debug, opts.Trace, opts.TraceVerbose); + } + + /// + /// Sets the server logger. + /// Mirrors Go Server.SetLogger(). + /// + public void SetLogger(INatsLogger? logger, bool debugFlag, bool traceFlag) + => SetLoggerV2(logger, debugFlag, traceFlag, false); + + /// + /// Sets the server logger and trace flags. + /// Mirrors Go Server.SetLoggerV2(). + /// + public void SetLoggerV2(INatsLogger? logger, bool debugFlag, bool traceFlag, bool sysTrace) + { + Interlocked.Exchange(ref _debugEnabled, debugFlag ? 1 : 0); + Interlocked.Exchange(ref _traceEnabled, traceFlag ? 1 : 0); + Interlocked.Exchange(ref _traceSysAcc, sysTrace ? 1 : 0); + + INatsLogger? previous; + lock (_loggingLock) + { + previous = _natsLogger; + _natsLogger = logger; + _logger = ToMicrosoftLogger(logger); + } + + if (previous is IDisposable disposable) + { + try + { + disposable.Dispose(); + } + catch (Exception ex) + { + _logger.LogError("Error closing logger: {Error}", ex.Message); + } + } + } + + /// + /// Re-opens file logger when file logging is enabled. + /// Mirrors Go Server.ReOpenLogFile(). + /// + public void ReOpenLogFile() + { + INatsLogger? activeLogger; + lock (_loggingLock) + { + activeLogger = _natsLogger; + } + + if (activeLogger == null) + { + Noticef("File log re-open ignored, no logger"); + return; + } + + var opts = GetOpts(); + if (string.IsNullOrEmpty(opts.LogFile)) + { + Noticef("File log re-open ignored, not a file logger"); + return; + } + + var fileLogger = new FileNatsLogger(opts.LogFile, opts.Logtime, opts.LogtimeUtc); + if (opts.LogSizeLimit > 0) + { + fileLogger.SetSizeLimit(opts.LogSizeLimit); + } + + if (opts.LogMaxFiles > 0) + { + var maxFiles = opts.LogMaxFiles > int.MaxValue ? 0 : (int)opts.LogMaxFiles; + fileLogger.SetMaxNumFiles(maxFiles); + } + + SetLogger(fileLogger, opts.Debug, opts.Trace); + Noticef("File log re-opened"); + } + + /// + /// Executes a logging callback if a logger is present. + /// Mirrors Go Server.executeLogCall(). + /// + internal void ExecuteLogCall(Action action) + { + INatsLogger? logger; + lock (_loggingLock) + { + logger = _natsLogger; + } + + if (logger == null) + { + return; + } + + action(logger); + } + + private static ILogger ToMicrosoftLogger(INatsLogger? logger) + { + return logger switch + { + null => NullLogger.Instance, + MicrosoftLoggerAdapter adapter => adapter.UnderlyingLogger, + _ => new NatsLoggerBridge(logger) + }; + } + + private sealed class NatsLoggerBridge(INatsLogger natsLogger) : ILogger + { + public IDisposable BeginScope(TState state) where TState : notnull + => NoopDisposable.Instance; + + public bool IsEnabled(LogLevel logLevel) => logLevel != LogLevel.None; + + public void Log( + LogLevel logLevel, + EventId eventId, + TState state, + Exception? exception, + Func formatter) + { + var message = formatter(state, exception); + if (exception != null) + { + message = $"{message}: {exception.Message}"; + } + + switch (logLevel) + { + case LogLevel.Trace: + natsLogger.Tracef("{0}", message); + break; + case LogLevel.Debug: + natsLogger.Debugf("{0}", message); + break; + case LogLevel.Information: + natsLogger.Noticef("{0}", message); + break; + case LogLevel.Warning: + natsLogger.Warnf("{0}", message); + break; + case LogLevel.Error: + natsLogger.Errorf("{0}", message); + break; + case LogLevel.Critical: + natsLogger.Fatalf("{0}", message); + break; + } + } + } + + private sealed class FileNatsLogger(string filePath, bool includeTimestamp, bool useUtc) : INatsLogger, IDisposable + { + private readonly object _sync = new(); + private readonly string _filePath = filePath; + private readonly bool _includeTimestamp = includeTimestamp; + private readonly bool _useUtc = useUtc; + private long _sizeLimit; + private int _maxNumFiles; + private bool _disposed; + + public void SetSizeLimit(long sizeLimit) + { + _sizeLimit = sizeLimit; + } + + public void SetMaxNumFiles(int maxNumFiles) + { + _maxNumFiles = maxNumFiles < 0 ? 0 : maxNumFiles; + } + + public void Noticef(string format, params object[] args) => Write("INF", format, args); + public void Warnf(string format, params object[] args) => Write("WRN", format, args); + public void Fatalf(string format, params object[] args) => Write("FTL", format, args); + public void Errorf(string format, params object[] args) => Write("ERR", format, args); + public void Debugf(string format, params object[] args) => Write("DBG", format, args); + public void Tracef(string format, params object[] args) => Write("TRC", format, args); + + public void Dispose() + { + _disposed = true; + } + + private void Write(string level, string format, object[] args) + { + if (_disposed) + { + return; + } + + var directory = Path.GetDirectoryName(_filePath); + if (!string.IsNullOrEmpty(directory)) + { + Directory.CreateDirectory(directory); + } + + var rendered = string.Format(format, args); + var line = BuildLine(level, rendered); + + lock (_sync) + { + RotateIfNeeded(line); + File.AppendAllText(_filePath, line, Encoding.UTF8); + } + } + + private string BuildLine(string level, string rendered) + { + if (!_includeTimestamp) + { + return $"[{level}] {rendered}{Environment.NewLine}"; + } + + var now = _useUtc ? DateTime.UtcNow : DateTime.Now; + return $"[{now:yyyy-MM-dd HH:mm:ss.fff}] [{level}] {rendered}{Environment.NewLine}"; + } + + private void RotateIfNeeded(string nextLine) + { + if (_sizeLimit <= 0) + { + return; + } + + var currentSize = File.Exists(_filePath) ? new FileInfo(_filePath).Length : 0L; + var nextSize = Encoding.UTF8.GetByteCount(nextLine); + if (currentSize + nextSize <= _sizeLimit) + { + return; + } + + RotateFiles(); + File.AppendAllText(_filePath, "Rotated log, backup saved" + Environment.NewLine, Encoding.UTF8); + } + + private void RotateFiles() + { + if (!File.Exists(_filePath)) + { + return; + } + + if (_maxNumFiles <= 1) + { + var backup = _filePath + ".bak"; + if (File.Exists(backup)) + { + File.Delete(backup); + } + + File.Move(_filePath, backup); + return; + } + + for (var i = _maxNumFiles - 1; i >= 1; i--) + { + var src = $"{_filePath}.{i}"; + var dst = $"{_filePath}.{i + 1}"; + + if (!File.Exists(src)) + { + continue; + } + + if (File.Exists(dst)) + { + File.Delete(dst); + } + + File.Move(src, dst); + } + + var firstBackup = $"{_filePath}.1"; + if (File.Exists(firstBackup)) + { + File.Delete(firstBackup); + } + + File.Move(_filePath, firstBackup); + } + } + + private sealed class NoopDisposable : IDisposable + { + public static NoopDisposable Instance { get; } = new(); + + public void Dispose() + { + } + } +} diff --git a/dotnet/tests/ZB.MOM.NatsNet.Server.Tests/Internal/ServerLoggerTests.cs b/dotnet/tests/ZB.MOM.NatsNet.Server.Tests/Internal/ServerLoggerTests.cs index 86d0681..42943b3 100644 --- a/dotnet/tests/ZB.MOM.NatsNet.Server.Tests/Internal/ServerLoggerTests.cs +++ b/dotnet/tests/ZB.MOM.NatsNet.Server.Tests/Internal/ServerLoggerTests.cs @@ -12,6 +12,8 @@ // 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; @@ -135,4 +137,130 @@ public class ServerLoggerTests _ = 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"); + } + + 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; + } } diff --git a/porting.db b/porting.db index ea997acdbdb4b9c3f6ffb46bf80703396dcdd32d..80d6d4341ab3c2cdb3d10343d259f0841bb05ebc 100644 GIT binary patch delta 1709 zcmcK4T})eL7zgma@9BBlLrZto7NkJoOynDGHIOjL!{KU6Ft<<>nD_Im9^93*MO%9C=YH7{tvfVOO?Q{%X z=}sr2bL@0xW9fHte1ZJL#aa3Xe>6*fq>g!GWsVYi>xoo)EM{+WbedYSRYVdBXr{8d zu&**(F;r#QN<`((R%TRrQ}T5R0+>NGb&0ap!P;TR=H(1TqMN|3)0}EI|f;_N+9rD3p z=o|Yc+!o1UdQ2TA9tcu}SIV+%r|+9D(-9h@U(k7@S(a}S664DEJ#Jp?luuS=-ivW< zG|`vP;#M)IGv{=af8>-)`M17k3Fn8R`BTeI8TNw{T;PTRD1@h=2s}^>B~S`pD1&lP z-~c=g6>t!qfkWVfN;nKvPz^`mDAa%-0uY2+sDpY4K^PjK5t^VGo`n`@h3DXTcmZC7 zm*5y2hnL|5yaFfTRd@|vhg0wdoQ5;-CPbhO&ca)84$i~d@D8*?2SlM0x}X~_7|YI{ z`c1(_ZgY#Qdh^5%^Si>w^mB6CAV1SN;?XZm58F&$>eVe?U9IcW)b!Y>ma@9IIvgzK zXZ-C>zHIBtJ704u+25ZS?yu=hH3vhD+uv?XP4^DeD`_=#saDa(6LD?0S5vl+HY>5Q z#9+L-FWEbm(&9>5OQn^56&qzlO<@m@q=>ffGdT1+^l#_~O zQkC$q5Zx_RuwnbYdz7ksdT=Y1n3GD}TB}b>pQJkX-?eHC?|G<8yM;1mLN%WK_n|d3 g?Rk)ky9J?K6}!SYYf@LcS5dORvVhT2sD3T|1Jw*xP5=M^ delta 970 zcmY+;T}V@590u@n-fi!8+;)83SIsnan)4%_Gryf_Wo6~JX&;*DY=K}TX+k&UOc26i z7r`q+;qJVWypRK3h(T9gi9$zZ)uPFfR-?@Q5-VrKb*`Bp z8&R@BCdS{!P2(Ehnjqhll_1&Gms$GyAA1dra+}~eNDY$8O2SEJjwBjMnn+TI(+Hai zQ-K;Z3Y(()Nz#V6DupDA_Pt_TpaVqo^6h=v&iq{gViLq+zvQ%MilUY8EYfG{@V|I) zOqIajEYTcIUO|bwP+44}+eB|{6n1csKlH@Ox2IKR{_-yF%y zFVk$x!M(pcpotMgcdOH$9RAVQW!mv?_K3o?E)L3U>oe*B@LbUDw zwe#>)-u|e~*F| zbRa<#=)nL+kQM)4^q@scyuvP#1)k$3i9C%lM%2SfC1W2%{UjMDqvR>+C0?HRsl&o! zO{_{yCWQ>X*~D`Bn29lyBnxo^zDM2nyM6a`sc15PYht#M1rvi9Fo78?V1@9vV{jbo z5DO