From 25403d938dee1330cd7f6cfb426712078d1cfac1 Mon Sep 17 00:00:00 2001 From: Nguyen Duy Date: Thu, 14 May 2026 17:27:47 +0700 Subject: [PATCH] feat: add diagnostic logger for debug info --- app/Log.cs | 90 +++++++++++++++++++++++++++++++++++++++++++ app/Program.cs | 11 ++++++ app/Tray.cs | 47 +++++++++++++++++++--- app/Vdd/Controller.cs | 43 ++++++++++++++++++++- app/Vdd/Core.cs | 4 +- 5 files changed, 185 insertions(+), 10 deletions(-) create mode 100644 app/Log.cs diff --git a/app/Log.cs b/app/Log.cs new file mode 100644 index 0000000..adc290a --- /dev/null +++ b/app/Log.cs @@ -0,0 +1,90 @@ +using System; +using System.Diagnostics; +using System.IO; +using System.Reflection; + +namespace ParsecVDisplay +{ + /// + /// Lightweight diagnostic logger. Appends to <exe-dir>\debug.log on each + /// launch (with a separator/header), and mirrors output to the attached + /// console (CLI / debugger). Thread-safe via a single file lock; both + /// destinations no-op silently on failure. + /// + internal static class Log + { + static readonly object FileLock = new object(); + static readonly string LogPath; + + static Log() + { + try + { + var exe = Assembly.GetExecutingAssembly().Location; + var dir = Path.GetDirectoryName(exe) ?? Environment.CurrentDirectory; + LogPath = Path.Combine(dir, "debug.log"); + + var sep = new string('=', 70); + var header = + sep + Environment.NewLine + + $"{Program.AppName} v{Program.AppVersion} | pid={Process.GetCurrentProcess().Id} | {DateTime.Now:yyyy-MM-dd HH:mm:ss}" + Environment.NewLine + + sep + Environment.NewLine; + File.AppendAllText(LogPath, header); + } + catch + { + LogPath = null; + } + } + + public static void Info (string msg) => Write("INF", msg, false); + public static void Debug(string msg) => Write("DBG", msg, false); + public static void Warn (string msg) => Write("WRN", msg, true); + public static void Error(string msg) => Write("ERR", msg, true); + + public static void Info (string fmt, params object[] args) => Write("INF", Fmt(fmt, args), false); + public static void Debug(string fmt, params object[] args) => Write("DBG", Fmt(fmt, args), false); + public static void Warn (string fmt, params object[] args) => Write("WRN", Fmt(fmt, args), true); + public static void Error(string fmt, params object[] args) => Write("ERR", Fmt(fmt, args), true); + + static string Fmt(string fmt, object[] args) + { + if (args == null || args.Length == 0) return fmt; + try { return string.Format(fmt, args); } + catch { return fmt; } + } + + static void Write(string level, string message, bool toStderr) + { + var line = $"[{DateTime.Now:HH:mm:ss.fff}] {level} {message}"; + + // Console — silent no-op for GUI processes with no attached console. + try + { + ConsoleColor? color = null; + switch (level) + { + case "DBG": color = ConsoleColor.DarkGray; break; + case "WRN": color = ConsoleColor.Yellow; break; + case "ERR": color = ConsoleColor.Red; break; + } + var prev = color.HasValue ? Console.ForegroundColor : ConsoleColor.Gray; + if (color.HasValue) Console.ForegroundColor = color.Value; + if (toStderr) Console.Error.WriteLine(line); + else Console.Out.WriteLine(line); + if (color.HasValue) Console.ForegroundColor = prev; + } + catch { /* no console attached */ } + + // File + if (LogPath != null) + { + lock (FileLock) + { + try { File.AppendAllText(LogPath, line + Environment.NewLine); } + catch { /* disk full, perms, etc — drop silently */ } + } + } + } + } +} diff --git a/app/Program.cs b/app/Program.cs index dea3963..ea721e0 100644 --- a/app/Program.cs +++ b/app/Program.cs @@ -16,6 +16,12 @@ namespace ParsecVDisplay [STAThread] static int Main(string[] args) { + // CLI mode runs short-lived against the user's terminal; skip the + // log header entirely to avoid polluting debug.log with help text + // queries. GUI mode triggers Log's static ctor on first use below. + if (args.Length == 0 || (args[0] != "-cli" && args[0] != "-custom")) + Log.Info("Main start: args=[{0}]", string.Join(" ", args)); + if (args.Length >= 2 && args[0] == "-custom") { var modes = Display.ParseModes(args[1]); @@ -44,6 +50,11 @@ namespace ParsecVDisplay Helper.StayAwake(false); Application.Run(new Tray()); + Log.Info("Main exit"); + } + else + { + Log.Info("Another instance already running, signaling and exiting"); } return 0; diff --git a/app/Tray.cs b/app/Tray.cs index 1d8735a..1aebf5f 100644 --- a/app/Tray.cs +++ b/app/Tray.cs @@ -66,6 +66,7 @@ namespace ParsecVDisplay public Tray() { + Log.Info("Tray initializing"); Instance = this; Vdd.Controller.Start(); @@ -266,6 +267,7 @@ namespace ParsecVDisplay int existing = Vdd.Core.GetDisplays().Count; int toAdd = Math.Max(0, wanted - existing); + Log.Info("Restore: wanted={0} existing={1} toAdd={2}", wanted, existing, toAdd); for (int i = 0; i < toAdd; i++) { @@ -278,8 +280,9 @@ namespace ParsecVDisplay if (i + 1 < toAdd) Thread.Sleep(500); } - catch + catch (Exception ex) { + Log.Warn("Restore: add {0}/{1} failed: {2}", i + 1, toAdd, ex.Message); break; } } @@ -293,7 +296,10 @@ namespace ParsecVDisplay Thread.Sleep(100); } if (displays == null || displays.Count == 0) + { + Log.Warn("Restore: no displays visible after add"); return; + } int n = Math.Min(displays.Count, states.Count); bool anyDeferred = false; @@ -308,10 +314,16 @@ namespace ParsecVDisplay if (displays[i].ChangeMode(s.Width, s.Height, s.Hz, s.Orientation, defer: true)) anyDeferred = true; + else + Log.Warn("Restore: ChangeMode[{0}] {1}x{2}@{3}/{4} failed", + i, s.Width, s.Height, s.Hz, (int)s.Orientation); } if (anyDeferred) + { Display.CommitChanges(); + Log.Info("Restore: committed {0} mode change(s)", n); + } } void ScheduleFallbackEvaluation(object sender, EventArgs e) @@ -346,22 +358,28 @@ namespace ParsecVDisplay { Vdd.Controller.AddDisplay(out int idx); FallbackDriverIndex = idx; + Log.Info("Fallback: added (no display present), index={0}", idx); + } + catch (Exception ex) + { + Log.Warn("Fallback: add failed: {0}", ex.Message); } - catch { } } else if (physical > 0 && FallbackDriverIndex >= 0) { // Physical returned; remove only our auto-added fallback. User- // added / restored displays stay (FallbackDriverIndex == -1 // means we didn't add them). + Log.Info("Fallback: physical display present, removing fallback index={0}", FallbackDriverIndex); try { Vdd.Controller.RemoveDisplay(FallbackDriverIndex); } - catch { } + catch (Exception ex) { Log.Warn("Fallback: remove failed: {0}", ex.Message); } FallbackDriverIndex = -1; } } void OnPowerModeChanged(object sender, PowerEvents.PowerBroadcastType type) { + Log.Info("Power event: {0}", type); switch (type) { case PowerEvents.PowerBroadcastType.PBT_APMSUSPEND: @@ -371,7 +389,7 @@ namespace ParsecVDisplay // resume path will re-evaluate fallback from scratch. FallbackDriverIndex = -1; try { SuspendSnapshot = Vdd.Controller.Suspend(); } - catch { } + catch (Exception ex) { Log.Warn("Suspend threw: {0}", ex.Message); } break; case PowerEvents.PowerBroadcastType.PBT_APMRESUMEAUTOMATIC: @@ -381,6 +399,8 @@ namespace ParsecVDisplay // Coalesce: Windows fires several resume events back-to-back. if (Interlocked.Exchange(ref ResumeHandled, 1) == 0) Task.Run(OnResume); + else + Log.Debug("Resume event coalesced (already handled)"); break; } } @@ -389,17 +409,25 @@ namespace ParsecVDisplay { try { + Log.Info("Resume: begin"); Vdd.Controller.Resume(); if (!Vdd.Controller.WaitForReady(10000)) + { + Log.Warn("Resume: timed out waiting for driver handle"); return; + } var snap = Interlocked.Exchange(ref SuspendSnapshot, null); if (snap == null || snap.Count == 0) + { + Log.Info("Resume: no snapshot to restore"); return; + } RestoreFromStates(snap); + Log.Info("Resume: done"); } - catch { } + catch (Exception ex) { Log.Error("Resume threw: {0}", ex); } } public void AddDisplay(object sender, EventArgs e) @@ -596,13 +624,17 @@ namespace ParsecVDisplay void Exit(object sender, EventArgs e) { var displays = Vdd.Core.GetDisplays(); + Log.Info("Exit requested ({0} displays, restore={1})", displays.Count, Config.RestoreDisplays); // Skip the "remove all displays?" prompt when restore is enabled — // the next launch will bring them right back. if (displays.Count > 0 && !Config.RestoreDisplays) { if (MessageBox.Show(Owner, App.GetTranslation("t_msg_prompt_leave_all"), Program.AppName, MessageBoxButtons.YesNo, MessageBoxIcon.Warning) != DialogResult.Yes) + { + Log.Info("Exit cancelled by user"); return; + } } SystemEvents.SessionEnding -= SaveDisplayState; @@ -623,7 +655,10 @@ namespace ParsecVDisplay for (int i = displays.Count - 1; i >= 0; i--) { try { Vdd.Controller.RemoveDisplay(displays[i].DisplayIndex); } - catch { } + catch (Exception ex) + { + Log.Warn("Exit: remove index {0} failed: {1}", displays[i].DisplayIndex, ex.Message); + } } App.Current?.Dispatcher.Invoke(App.Current.Shutdown); diff --git a/app/Vdd/Controller.cs b/app/Vdd/Controller.cs index 3f73d86..3081fb7 100644 --- a/app/Vdd/Controller.cs +++ b/app/Vdd/Controller.cs @@ -42,10 +42,12 @@ namespace ParsecVDisplay.Vdd UpdateThread.Start(); StatusThread.Start(); + Log.Info("Controller started"); } public static void Stop() { + Log.Info("Controller stopping"); Cancellation?.Cancel(); StatusKick?.Set(); UpdateThread?.Join(); @@ -56,6 +58,7 @@ namespace ParsecVDisplay.Vdd StatusKick?.Dispose(); HandleReady?.Dispose(); + Log.Info("Controller stopped"); } /// @@ -89,6 +92,7 @@ namespace ParsecVDisplay.Vdd var displays = Core.GetDisplays(); var snapshot = displays.ConvertAll(d => d.Snapshot()); + Log.Info("Suspend: snapshot {0} display(s)", snapshot.Count); Suspended = true; @@ -99,7 +103,7 @@ namespace ParsecVDisplay.Vdd for (int i = displays.Count - 1; i >= 0; i--) { try { Core.RemoveDisplay(VddHandle, displays[i].DisplayIndex); } - catch { /* best effort */ } + catch (Exception ex) { Log.Warn("Suspend: remove index {0} failed: {1}", displays[i].DisplayIndex, ex.Message); } } } @@ -117,6 +121,7 @@ namespace ParsecVDisplay.Vdd /// public static void Resume() { + Log.Info("Resume"); Suspended = false; StatusKick?.Set(); } @@ -149,8 +154,11 @@ namespace ParsecVDisplay.Vdd continue; } + var prev = LastStatus; var status = QueryStatus(out var _); Volatile.Write(ref LastStatusValue, (int)status); + if (status != prev) + Log.Info("Driver status: {0} -> {1}", prev, status); if (status == Device.Status.OK) { @@ -159,7 +167,14 @@ namespace ParsecVDisplay.Vdd Device.OpenHandle(Core.ADAPTER_GUID, out var handle); Interlocked.Exchange(ref VddHandle, handle); if (handle.IsValidHandle()) + { HandleReady.Set(); + Log.Info("Handle opened"); + } + else + { + Log.Warn("Failed to open device handle while status is OK"); + } } } else @@ -169,6 +184,7 @@ namespace ParsecVDisplay.Vdd { HandleReady.Reset(); Device.CloseHandle(handle); + Log.Info("Handle closed (status={0})", status); } } @@ -200,38 +216,63 @@ namespace ParsecVDisplay.Vdd var status = QueryStatus(); if (status != Device.Status.OK) + { + Log.Warn("AddDisplay refused: driver status = {0}", status); throw new ErrorDriverStatus(status); + } int limit = Core.MAX_DISPLAYS; var displays = Core.GetDisplays(); if (displays.Count >= limit) + { + Log.Warn("AddDisplay refused: limit {0} reached", limit); throw new ErrorExceededLimit(limit); + } // Snapshot the handle ONCE so StatusLoop closing it after this // check doesn't leave us calling DeviceIoControl on a stale value. var handle = VddHandle; if (!handle.IsValidHandle()) + { + Log.Warn("AddDisplay refused: handle not open"); throw new ErrorDeviceHandle(); + } if (!Core.AddDisplay(handle, out driverIndex)) + { + Log.Error("AddDisplay: IOCTL failed"); throw new ErrorOperationFailed(ErrorOperationFailed.Operation.AddDisplay); + } + + Log.Info("AddDisplay: index={0}", driverIndex); } public static void RemoveDisplay(int index) { var status = QueryStatus(); if (status != Device.Status.OK) + { + Log.Warn("RemoveDisplay({0}) refused: driver status = {1}", index, status); throw new ErrorDriverStatus(status); + } if (index < 0) return; if (!VddHandle.IsValidHandle()) + { + Log.Warn("RemoveDisplay({0}) refused: handle not open", index); throw new ErrorDeviceHandle(); + } if (!Core.RemoveDisplay(VddHandle, index)) + { + Log.Error("RemoveDisplay({0}): IOCTL failed", index); throw new ErrorOperationFailed(ErrorOperationFailed.Operation.RemoveDisplay); + } + + Log.Info("RemoveDisplay: index={0}", index); } public static void RemoveLastDisplay() diff --git a/app/Vdd/Core.cs b/app/Vdd/Core.cs index f74f6b6..3ab47ff 100644 --- a/app/Vdd/Core.cs +++ b/app/Vdd/Core.cs @@ -184,11 +184,9 @@ namespace ParsecVDisplay.Vdd bool success = Native.GetOverlappedResultEx(handle, ref Overlapped, out var _, timeout, false); -#if DEBUG if (code != IoCtlCode.IOCTL_UPDATE) - Console.WriteLine("[D] IoControl: {0} -> {1}, err={2}", + Log.Debug("IoControl {0} -> {1}, err={2}", code, success, DumpErrorCode(Marshal.GetLastWin32Error())); -#endif // If the wait fails (timeout/error), the IO may still be // pending in the kernel. Cancel and BLOCK until truly done