using System.Text; using System.Text.Json; namespace Ananta.SDK.Logging; /// /// Process-wide runtime logs shared by the SDK and server. /// Run-All.ps1 supplies one run id so C# and the Node proxy append to the same console files. /// public static class RuntimeLogs { private static readonly object FileLock = new(); private static readonly JsonSerializerOptions JsonOptions = new() { IncludeFields = true, WriteIndented = false, MaxDepth = 8, }; private static bool _initialized; private static bool _consoleEnabled; private static bool _packetEnabled; private static bool _includeHex; private static bool _includeDecoded; private static int _maxBodyBytes; private static string? _consoleLatest; private static string? _consoleArchive; private static string? _packetLatest; private static string? _packetArchive; // ⛑️⛑️ 长驻 writer —— 见 AppendText 的注释。原来每一行日志都要 // 「CreateDirectory + new FileStream(Append) + new StreamWriter + 写 + 释放」×2 份文件, // 而 FileMode.Append 每次打开都要重新定位到 EOF ⇒ 单行的代价随日志文件变大而变大。 // 实测:SyncPlayerInfo 那 200 KB 的 hexdump 有 12 541 行,在 09-30 16:50(日志还小) // 要 2.8 s,到 10-01 22:08(日志 20 MB)要 6.8~14.1 s —— 而这段时间是**同步**跑在 // LoginGame handler 里的(RpcContext.NotifyAsync 写完包立刻 RuntimeLogs.Decoded), // 收包循环串行 ⇒ 一帧都不读 ⇒ 客户端 TimeScaleAnomaly 判定掉线 ⇒ 重连 ⇒ 又打一份 // 200 KB 的 hexdump ⇒ 日志更大 ⇒ 更慢。正反馈,永不收敛。 private static StreamWriter? _consoleLatestWriter; private static StreamWriter? _consoleArchiveWriter; private static StreamWriter? _packetLatestWriter; private static StreamWriter? _packetArchiveWriter; private static TextWriter? _originalOut; private static TextWriter? _originalError; private static bool _bootstrapConsoleHidden; public static void Initialize( string logDirectory, string? runId, bool consoleEnabled, bool packetEnabled, bool includeHex, bool includeDecoded, int maxBodyBytes) { if (_initialized) return; Directory.CreateDirectory(logDirectory); runId = string.IsNullOrWhiteSpace(runId) ? DateTime.Now.ToString("yyyyMMdd-HHmmss") : runId; _consoleEnabled = consoleEnabled; _packetEnabled = packetEnabled; _includeHex = includeHex; _includeDecoded = includeDecoded; _maxBodyBytes = Math.Max(0, maxBodyBytes); _consoleLatest = Environment.GetEnvironmentVariable("Ananta_CONSOLE_LOG_LATEST") ?? Environment.GetEnvironmentVariable("DRMK_CONSOLE_LOG_LATEST") ?? Path.Combine(logDirectory, "console-latest.log"); _consoleArchive = Environment.GetEnvironmentVariable("Ananta_CONSOLE_LOG_ARCHIVE") ?? Environment.GetEnvironmentVariable("DRMK_CONSOLE_LOG_ARCHIVE") ?? Path.Combine(logDirectory, $"console-{runId}.log"); _packetLatest = Environment.GetEnvironmentVariable("DRMK_PACKET_LOG_LATEST") ?? Path.Combine(logDirectory, "packets-latest.log"); _packetArchive = Environment.GetEnvironmentVariable("DRMK_PACKET_LOG_ARCHIVE") ?? Path.Combine(logDirectory, $"packets-{runId}.log"); // When launched without Run-All, create a fresh latest/archive pair here. if (Environment.GetEnvironmentVariable("DRMK_LOGS_PREPARED") != "1") { if (_consoleEnabled) { PrepareFile(_consoleLatest); PrepareFile(_consoleArchive); } if (_packetEnabled) { PrepareFile(_packetLatest); PrepareFile(_packetArchive); } } // 文件已经 PrepareFile 过(或由 Run-All 预先清空),这里一次性打开并常驻。 // ⛑ latest 与 archive 指向同一个文件时只开一个 writer —— 两个 Append 流写同一个文件 // 会各自维护文件指针、互相覆盖(旧代码是每次重写,所以没这个问题)。 _consoleLatestWriter = _consoleEnabled ? OpenWriter(_consoleLatest) : null; _consoleArchiveWriter = _consoleEnabled && !SamePath(_consoleLatest, _consoleArchive) ? OpenWriter(_consoleArchive) : null; _packetLatestWriter = _packetEnabled ? OpenWriter(_packetLatest) : null; _packetArchiveWriter = _packetEnabled && !SamePath(_packetLatest, _packetArchive) ? OpenWriter(_packetArchive) : null; _initialized = true; if (_consoleEnabled) { _originalOut = Console.Out; _originalError = Console.Error; _bootstrapConsoleHidden = Environment.GetEnvironmentVariable("DRMK_HIDE_BOOT_LOG") == "1"; if (_bootstrapConsoleHidden) { // Run-All already cleared the launcher window. Keep startup diagnostics in the // normal console log files without repainting the interactive console. Console.SetOut(new MirrorOnlyTextWriter(_originalOut.Encoding, AppendConsole)); Console.SetError(new MirrorOnlyTextWriter(_originalError.Encoding, AppendConsole)); } else { Console.SetOut(new TeeTextWriter(_originalOut, AppendConsole)); Console.SetError(new TeeTextWriter(_originalError, AppendConsole)); } } } /// Restore normal runtime console output after boot diagnostics have completed. public static void EndBootstrapQuietMode() { if (!_initialized || !_consoleEnabled || !_bootstrapConsoleHidden || _originalOut is null || _originalError is null) return; Console.SetOut(new TeeTextWriter(_originalOut, AppendConsole)); Console.SetError(new TeeTextWriter(_originalError, AppendConsole)); _bootstrapConsoleHidden = false; } public static void Incoming(string scope, RpcPacketKindView kind, uint methodId, int invokeId, ReadOnlySpan body) => WritePacket(scope, "C2S", kind.ToString().ToUpperInvariant(), methodId, invokeId, null, body); public static void OutgoingNotify(string scope, uint methodId, ReadOnlySpan body) => WritePacket(scope, "S2C", "NOTIFY", methodId, 0, null, body); public static void OutgoingReturn(string scope, uint methodId, int invokeId, int error, ReadOnlySpan body) => WritePacket(scope, "S2C", "RETURN", methodId, invokeId, error, body); public static void RawFrame(string scope, string direction, byte mode, ReadOnlySpan payload, string note) { if (!_initialized || !_packetEnabled) return; AppendPacket($"{Timestamp()} [{scope}] {direction} FRAME mode=0x{mode:X2} note={note} payload={payload.Length}b"); if (!_includeHex || payload.Length == 0) return; var count = _maxBodyBytes == 0 ? payload.Length : Math.Min(payload.Length, _maxBodyBytes); foreach (var line in HexDump(payload[..count])) AppendPacket($" {line}"); if (count < payload.Length) AppendPacket($" ... truncated {payload.Length - count} bytes (logging.packets.maxBodyBytes={_maxBodyBytes})"); } public static void Decoded(string scope, string direction, uint methodId, Type contractType, object? value) { if (!_initialized || !_packetEnabled || !_includeDecoded) return; string json; try { json = JsonSerializer.Serialize(value, contractType, JsonOptions); } catch (Exception ex) { json = $""; } AppendPacket($"{Timestamp()} [{scope}] {direction} DECODED {RpcMethodNames.Display(methodId)} type={contractType.Name} {json}"); } private static void WritePacket( string scope, string direction, string kind, uint methodId, int invokeId, int? error, ReadOnlySpan body) { if (!_initialized || !_packetEnabled) return; var invoke = invokeId != 0 ? $" invoke={invokeId}" : string.Empty; var err = error.HasValue ? $" error={error.Value}" : string.Empty; AppendPacket($"{Timestamp()} [{scope}] {direction} {kind} {RpcMethodNames.Display(methodId)}{invoke}{err} body={body.Length}b"); if (!_includeHex || body.Length == 0) return; var count = _maxBodyBytes == 0 ? body.Length : Math.Min(body.Length, _maxBodyBytes); foreach (var line in HexDump(body[..count])) AppendPacket($" {line}"); if (count < body.Length) AppendPacket($" ... truncated {body.Length - count} bytes (logging.packets.maxBodyBytes={_maxBodyBytes})"); } private static List HexDump(ReadOnlySpan body) { const int width = 16; var lines = new List((body.Length + width - 1) / width); for (var offset = 0; offset < body.Length; offset += width) { var len = Math.Min(width, body.Length - offset); var slice = body.Slice(offset, len); var hex = new StringBuilder(width * 3); var ascii = new StringBuilder(width); for (var i = 0; i < width; i++) { if (i < len) { var b = slice[i]; hex.Append(b.ToString("X2")).Append(' '); ascii.Append(b is >= 32 and <= 126 ? (char)b : '.'); } else { hex.Append(" "); ascii.Append(' '); } } lines.Add($"{offset:X8} {hex}|{ascii}|"); } return lines; } private static string Timestamp() => DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fff"); private static void AppendConsole(string text) { if (!_initialized || !_consoleEnabled || string.IsNullOrEmpty(text)) return; AppendToPair(_consoleLatestWriter, _consoleArchiveWriter, text); } private static void AppendPacket(string line) => AppendToPair(_packetLatestWriter, _packetArchiveWriter, line + Environment.NewLine); private static void AppendToPair(StreamWriter? latest, StreamWriter? archive, string text) { lock (FileLock) { latest?.Write(text); if (!ReferenceEquals(latest, archive)) archive?.Write(text); } } /// /// 一次性打开日志文件的长驻 writer。 /// /// ⛑️ 这里不能回到「每行 new FileStream(FileMode.Append)」的写法:Append 模式每次 /// 打开都要重新定位到 EOF,单行代价随文件体积线性上涨,20 MB 的 packets 日志上实测 /// ~0.5 ms/行 ×2 份文件 —— 一个 200 KB 包的 hexdump(12 541 行)就是 10 秒级同步阻塞, /// 而它发生在 RPC handler 里(见上面 writer 字段的注释)。 /// private static StreamWriter? OpenWriter(string? path) { if (string.IsNullOrWhiteSpace(path)) return null; Directory.CreateDirectory(Path.GetDirectoryName(Path.GetFullPath(path))!); var stream = new FileStream(path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite | FileShare.Delete); // AutoFlush=true:玩家/我自己是边跑边看 console-latest.log 的,不能为了省一次 // syscall 把尾巴攒在缓冲区里。真正的开销在「打开/关闭」而不在 flush。 return new StreamWriter(stream, new UTF8Encoding(false)) { AutoFlush = true }; } private static bool SamePath(string? a, string? b) => !string.IsNullOrWhiteSpace(a) && !string.IsNullOrWhiteSpace(b) && string.Equals(Path.GetFullPath(a), Path.GetFullPath(b), StringComparison.OrdinalIgnoreCase); /// 把长驻 writer 全部 flush(进程正常退出时调用一次,可选)。 public static void FlushAll() { lock (FileLock) { _consoleLatestWriter?.Flush(); _consoleArchiveWriter?.Flush(); _packetLatestWriter?.Flush(); _packetArchiveWriter?.Flush(); } } private static void PrepareFile(string? path) { if (string.IsNullOrWhiteSpace(path)) return; Directory.CreateDirectory(Path.GetDirectoryName(Path.GetFullPath(path))!); File.WriteAllText(path, string.Empty, new UTF8Encoding(false)); } private sealed class MirrorOnlyTextWriter(Encoding encoding, Action mirror) : TextWriter { public override Encoding Encoding => encoding; public override void Write(char value) => mirror(value.ToString()); public override void Write(string? value) { if (!string.IsNullOrEmpty(value)) mirror(value); } public override void WriteLine(string? value) => mirror((value ?? string.Empty) + Environment.NewLine); public override void WriteLine() => mirror(Environment.NewLine); } private sealed class TeeTextWriter(TextWriter original, Action mirror) : TextWriter { public override Encoding Encoding => original.Encoding; public override void Write(char value) { original.Write(value); mirror(value.ToString()); } public override void Write(string? value) { original.Write(value); if (!string.IsNullOrEmpty(value)) mirror(value); } public override void WriteLine(string? value) { original.WriteLine(value); mirror((value ?? string.Empty) + Environment.NewLine); } public override void WriteLine() { original.WriteLine(); mirror(Environment.NewLine); } } } /// Small SDK-only view so the logging layer does not depend on RPC implementation types. public enum RpcPacketKindView { Invoke, Notify, Return, } /// Global names populated by RpcRouter.Name; outgoing packets can therefore log symbolic MethodId names too. public static class RpcMethodNames { private static readonly object Lock = new(); private static readonly Dictionary Names = new(); public static void Register(uint methodId, string name) { lock (Lock) Names.TryAdd(methodId, name); } public static string Display(uint methodId) { lock (Lock) return Names.TryGetValue(methodId, out var name) ? $"{name} [0x{methodId:X8}]" : $"0x{methodId:X8}"; } }