Ananta-ps/Ananta.SDK/Logging/RuntimeLogs.cs

using System.Text;
using System.Text.Json;

namespace Ananta.SDK.Logging;

/// <summary>
/// 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.
/// </summary>
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<T> 写完包立刻 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));
            }
        }
    }

    /// <summary>Restore normal runtime console output after boot diagnostics have completed.</summary>
    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<byte> body)
        => WritePacket(scope, "C2S", kind.ToString().ToUpperInvariant(), methodId, invokeId, null, body);

    public static void OutgoingNotify(string scope, uint methodId, ReadOnlySpan<byte> body)
        => WritePacket(scope, "S2C", "NOTIFY", methodId, 0, null, body);

    public static void OutgoingReturn(string scope, uint methodId, int invokeId, int error, ReadOnlySpan<byte> body)
        => WritePacket(scope, "S2C", "RETURN", methodId, invokeId, error, body);

    public static void RawFrame(string scope, string direction, byte mode, ReadOnlySpan<byte> 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 = $"<decode-log-failed {ex.GetType().Name}: {ex.Message}>";
        }

        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<byte> 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<string> HexDump(ReadOnlySpan<byte> body)
    {
        const int width = 16;
        var lines = new List<string>((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);
        }
    }

    /// <summary>
    /// 一次性打开日志文件的长驻 writer。
    ///
    /// ⛑️ 这里<b>不能</b>回到「每行 new FileStream(FileMode.Append)」的写法：Append 模式每次
    /// 打开都要重新定位到 EOF，单行代价随文件体积线性上涨，20 MB 的 packets 日志上实测
    /// ~0.5 ms/行 ×2 份文件 —— 一个 200 KB 包的 hexdump（12 541 行）就是 10 秒级同步阻塞，
    /// 而它发生在 RPC handler 里（见上面 writer 字段的注释）。
    /// </summary>
    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);

    /// <summary>把长驻 writer 全部 flush（进程正常退出时调用一次，可选）。</summary>
    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<string> 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<string> 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);
        }
    }
}

/// <summary>Small SDK-only view so the logging layer does not depend on RPC implementation types.</summary>
public enum RpcPacketKindView
{
    Invoke,
    Notify,
    Return,
}

/// <summary>Global names populated by RpcRouter.Name; outgoing packets can therefore log symbolic MethodId names too.</summary>
public static class RpcMethodNames
{
    private static readonly object Lock = new();
    private static readonly Dictionary<uint, string> 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}";
    }
}