feat: add diagnostic logger for debug info

This commit is contained in:
Nguyen Duy
2026-05-14 17:27:47 +07:00
parent 9b625a5bf5
commit 25403d938d
5 changed files with 185 additions and 10 deletions
+90
View File
@@ -0,0 +1,90 @@
using System;
using System.Diagnostics;
using System.IO;
using System.Reflection;
namespace ParsecVDisplay
{
/// <summary>
/// Lightweight diagnostic logger. Appends to &lt;exe-dir&gt;\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.
/// </summary>
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 */ }
}
}
}
}
}
+11
View File
@@ -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;
+41 -6
View File
@@ -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);
+42 -1
View File
@@ -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");
}
/// <summary>
@@ -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
/// </summary>
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()
+1 -3
View File
@@ -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