diff --git a/CHANGELOG.md b/CHANGELOG.md index 0d2f9d6..6629a49 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -40,6 +40,7 @@ The newest entry must match the version in `WandEnhancer/Properties/AssemblyInfo ### Improvements +- The launcher now writes a `launcher.log` next to itself, recording every process Electron starts and whether its fuse was cleared, exit and crash codes, and how long it stayed attached. Starting Wand happens without a window, so until now a client that refused to open left nothing to go on. - Log messages in the desktop app are now translated into all 12 supported languages. - The remote panel is now usable with a keyboard and a screen reader: dialogs trap focus and close on Escape, and controls have accessible names. Pinning a mod previously required a swipe and had no keyboard path at all, so mod rows now have a pin button. diff --git a/WandEnhancer/Core/FuseLauncher.cs b/WandEnhancer/Core/FuseLauncher.cs index f256998..24c3f1b 100644 --- a/WandEnhancer/Core/FuseLauncher.cs +++ b/WandEnhancer/Core/FuseLauncher.cs @@ -4,6 +4,7 @@ using System.IO; using System.Diagnostics; using System.Runtime.InteropServices; using System.Text; +using WandEnhancer.View.MainWindow; namespace WandEnhancer.Core { @@ -41,6 +42,9 @@ namespace WandEnhancer.Core private const int OffsetThreadId = 8; private const int OffsetUnion = 16; private const int OffsetExceptionCode = OffsetUnion; + // EXCEPTION_DEBUG_INFO is EXCEPTION_RECORD (152 bytes on x64) followed by dwFirstChance. + private const int OffsetExceptionFirstChance = OffsetUnion + 152; + private const int OffsetExitCode = OffsetUnion; private const int OffsetCreateProcessFile = OffsetUnion; private const int OffsetCreateProcessHandle = OffsetUnion + 8; private const int OffsetCreateProcessImageBase = OffsetUnion + 24; @@ -51,10 +55,17 @@ namespace WandEnhancer.Core private const long QuietMs = 1500; private const long MaxDebugMs = 9000; + // Electron dies a second or two after a renderer fails, which is past the detach. + // Watching that window is the only way the exit code reaches the log. + private const int PostDetachWatchMs = 5000; + + /// Electron's exit code when the ASAR integrity fuse rejects the archive. + private const int AsarIntegrityExitCode = -36861; + private static readonly byte[] Sentinel = Encoding.ASCII.GetBytes("dL7pKGdnNz796PbbjQWNKmHXBZaB9tsX"); - public static bool Launch(string exePath, string args, Action log = null) + public static bool Launch(string exePath, string args, Action log = null) { var si = new STARTUPINFO { cb = Marshal.SizeOf() }; var cmdLine = new StringBuilder( @@ -64,20 +75,35 @@ namespace WandEnhancer.Core false, DEBUG_PROCESS, IntPtr.Zero, Path.GetDirectoryName(exePath), ref si, out var pi)) { - log?.Invoke($"Could not start Wand under the fuse patcher (win32 error {Marshal.GetLastWin32Error()})."); + log?.Invoke($"Could not start Wand under the fuse patcher (win32 error {Marshal.GetLastWin32Error()}).", + ELogType.Error); return false; } // Debugged processes must survive after we detach and exit. DebugSetProcessKillOnExit(false); CloseHandle(pi.hThread); - CloseHandle(pi.hProcess); + log?.Invoke($"Started {exePath} as pid {pi.dwProcessId}.", ELogType.Info); + + try + { + // The process handle outlives the debug loop on purpose: once detached it is + // the only remaining way to read why Wand died. + if (!DrivePatchingDebugLoop(pi.dwProcessId, log)) + { + WatchAfterDetach(pi.hProcess, log); + } + } + finally + { + CloseHandle(pi.hProcess); + } - DrivePatchingDebugLoop(pi.dwProcessId, log); return true; } - private static void DrivePatchingDebugLoop(int mainPid, Action log) + /// True when the main process exited while the debugger was still attached. + private static bool DrivePatchingDebugLoop(int mainPid, Action log) { var pids = new List(); var brokeIn = new HashSet(); @@ -86,6 +112,8 @@ namespace WandEnhancer.Core // every ~25 days, and a negative elapsed would keep the debugger attached forever. var clock = Stopwatch.StartNew(); long lastCreate = 0; + int created = 0; + int patched = 0; while (true) { @@ -109,8 +137,13 @@ namespace WandEnhancer.Core var hProc = (IntPtr)BitConverter.ToInt64(evt, OffsetCreateProcessHandle); var baseImg = (IntPtr)BitConverter.ToInt64(evt, OffsetCreateProcessImageBase); if (!pids.Contains(pid)) pids.Add(pid); - if (!PatchFuse(hProc, baseImg)) - log?.Invoke($"Fuse not cleared in pid {pid}; renderers may fail with -36861."); + created++; + bool cleared = PatchFuse(hProc, baseImg); + if (cleared) patched++; + log?.Invoke( + $"pid {pid} started at {now} ms - fuse " + + (cleared ? "cleared." : $"NOT cleared, it may exit with {AsarIntegrityExitCode}."), + cleared ? ELogType.Info : ELogType.Warn); // The debugger owns the image handle the kernel hands over with this event. if (hFile != IntPtr.Zero) CloseHandle(hFile); lastCreate = now; @@ -122,14 +155,27 @@ namespace WandEnhancer.Core status = (exCode == EXCEPTION_BREAKPOINT && brokeIn.Add(pid)) ? DBG_CONTINUE : DBG_EXCEPTION_NOT_HANDLED; + // Chromium raises first-chance exceptions constantly and handles them. + // A second chance means nothing handled it and the process is dying. + if (BitConverter.ToInt32(evt, OffsetExceptionFirstChance) == 0) + log?.Invoke($"pid {pid} hit an unhandled exception at {now} ms: {DescribeCode(exCode)}.", + ELogType.Error); break; case EXIT_PROCESS_DEBUG_EVENT: + int exitCode = BitConverter.ToInt32(evt, OffsetExitCode); pids.Remove(pid); + log?.Invoke( + $"{(pid == mainPid ? "Main process" : $"pid {pid}")} exited at {now} ms " + + $"with code {DescribeCode(exitCode)}.", + exitCode == 0 ? ELogType.Info : ELogType.Error); + if (pid == mainPid) { + log?.Invoke($"Wand exited during startup: {created} processes started, {patched} fuse-patched.", + ELogType.Error); ContinueDebugEvent(pid, tid, status); - return; + return true; } break; } @@ -141,8 +187,59 @@ namespace WandEnhancer.Core break; } + long detachedAt = clock.ElapsedMilliseconds; + // The detach reason matters: hitting the cap means Electron was still spawning + // processes we never patched, which looks exactly like "Wand does not open". + string reason = detachedAt > MaxDebugMs + ? $"{MaxDebugMs} ms cap reached" + : $"no new process for {QuietMs} ms"; + log?.Invoke( + $"Detached after {detachedAt} ms ({reason}): {created} processes started, " + + $"{patched} fuse-patched, {pids.Count} still attached.", + patched == 0 ? ELogType.Error : ELogType.Info); + foreach (var pid in pids) DebugActiveProcessStop(pid); + + return false; + } + + /// + /// Electron usually dies a second or two after a renderer fails, which lands after the + /// detach. Without this the log ends on a healthy-looking "detached" line. + /// + private static void WatchAfterDetach(IntPtr hProcess, Action log) + { + if (WaitForSingleObject(hProcess, PostDetachWatchMs) != WAIT_OBJECT_0) + { + log?.Invoke($"Wand still running {PostDetachWatchMs} ms after detach.", ELogType.Success); + return; + } + + if (!GetExitCodeProcess(hProcess, out int exitCode)) + { + log?.Invoke($"Wand exited after detach, exit code unreadable (win32 error {Marshal.GetLastWin32Error()}).", + ELogType.Error); + return; + } + + log?.Invoke($"Wand exited right after detach with code {DescribeCode(exitCode)}.", ELogType.Error); + } + + /// Names the exit and exception codes that actually turn up when Wand will not start. + private static string DescribeCode(int code) + { + switch (code) + { + case 0: return "0"; + case AsarIntegrityExitCode: + return $"{code} (ASAR integrity check failed - the fuse was not cleared in that process)"; + case unchecked((int)0xC0000005): return $"0x{code:X8} (access violation)"; + case unchecked((int)0xC0000135): return $"0x{code:X8} (a required DLL is missing)"; + case unchecked((int)0xC0000142): return $"0x{code:X8} (a DLL failed to initialise)"; + case unchecked((int)0xC0000409): return $"0x{code:X8} (stack buffer overrun)"; + default: return $"{code} (0x{code:X8})"; + } } private static bool ShouldDetach(long elapsed, long sinceLastCreate) @@ -229,6 +326,7 @@ namespace WandEnhancer.Core private const int CREATE_PROCESS_DEBUG_EVENT = 3; private const int EXIT_PROCESS_DEBUG_EVENT = 5; private const int EXCEPTION_BREAKPOINT = unchecked((int)0x80000003); + private const uint WAIT_OBJECT_0 = 0; [StructLayout(LayoutKind.Sequential)] private struct STARTUPINFO @@ -283,6 +381,12 @@ namespace WandEnhancer.Core [DllImport("kernel32.dll", SetLastError = true)] private static extern bool DebugSetProcessKillOnExit(bool KillOnExit); + [DllImport("kernel32.dll", SetLastError = true)] + private static extern uint WaitForSingleObject(IntPtr hHandle, int dwMilliseconds); + + [DllImport("kernel32.dll", SetLastError = true)] + private static extern bool GetExitCodeProcess(IntPtr hProcess, out int lpExitCode); + [DllImport("kernel32.dll")] private static extern bool CloseHandle(IntPtr hObject); diff --git a/WandEnhancer/Core/LauncherLog.cs b/WandEnhancer/Core/LauncherLog.cs new file mode 100644 index 0000000..ae3945f --- /dev/null +++ b/WandEnhancer/Core/LauncherLog.cs @@ -0,0 +1,60 @@ +using System; +using System.IO; +using WandEnhancer.View.MainWindow; + +namespace WandEnhancer.Core +{ + /// + /// Append-only log written next to the deployed launcher. Launch mode has no window and + /// exits as soon as Wand is up, so without this file a "Wand does not start" report + /// carries no evidence at all. Every operation swallows its own failure: diagnostics must + /// never be the reason Wand fails to launch. + /// + internal static class LauncherLog + { + public const string FileName = "launcher.log"; + private const long MaxBytes = 512 * 1024; + + private static string _path; + + public static void Open(string launcherDirectory, string header) + { + try + { + var file = new FileInfo(Path.Combine(launcherDirectory, FileName)); + // Dropped whole rather than trimmed: the session being diagnosed is the last + // one, and keeping half a rotated file is not worth the code. + if (file.Exists && file.Length > MaxBytes) + { + file.Delete(); + } + + _path = file.FullName; + Write($"=== {DateTime.Now:yyyy-MM-dd} {header}", ELogType.Info); + } + catch (Exception e) when (e is IOException || e is UnauthorizedAccessException || + e is ArgumentException || e is NotSupportedException) + { + _path = null; + } + } + + public static void Write(string message, ELogType type) + { + if (_path == null) + { + return; + } + + try + { + File.AppendAllText(_path, + $"{DateTime.Now:HH:mm:ss.fff} [{type.ToString().ToUpperInvariant()}] {message}{Environment.NewLine}"); + } + catch (Exception e) when (e is IOException || e is UnauthorizedAccessException) + { + // A log line lost to a locked or full disk must not abort the launch. + } + } + } +} diff --git a/WandEnhancer/Program.cs b/WandEnhancer/Program.cs index 07866e7..cf75b3f 100644 --- a/WandEnhancer/Program.cs +++ b/WandEnhancer/Program.cs @@ -44,28 +44,45 @@ namespace WandEnhancer return false; string myDir = Path.GetDirectoryName(myExe); + string forwardedArgs = args.Length > 0 ? QuoteArguments(args) : null; + + LauncherLog.Open(myDir, $"WandEnhancer {Constants.Version} | {myExe}" + + (forwardedArgs == null ? "" : $" | args {forwardedArgs}")); if (args.Length > 0 && args[0].StartsWith("--squirrel", StringComparison.OrdinalIgnoreCase)) { string updateExe = Path.Combine(myDir, "Update.exe"); if (File.Exists(updateExe)) + { + LauncherLog.Write($"Squirrel hook {args[0]} forwarded to Update.exe.", ELogType.Info); Process.Start(updateExe, QuoteArguments(args)); + } + else + { + LauncherLog.Write($"Squirrel hook {args[0]} ignored: Update.exe is missing.", ELogType.Warn); + } + return true; } var config = WeModInstalls.FindLatestWeMod(myDir); if (config == null) + { + LauncherLog.Write($"No Wand install found under {myDir}; opening the UI instead.", ELogType.Error); return false; + } + + bool isPatched = Enhancer.IsPatched(config.RootDirectory); + LauncherLog.Write($"Install {config.ExecutablePath} is {(isPatched ? "patched" : "not patched")}.", + ELogType.Info); // A fresh Wand version drops our patches; re-apply the saved selection automatically. // On failure fall through to the UI so the user sees which patch broke. - if (!Enhancer.IsPatched(config.RootDirectory) && !TryAutoPatch(config, myDir)) + if (!isPatched && !TryAutoPatch(config, myDir)) return false; - string forwardedArgs = args.Length > 0 ? QuoteArguments(args) : null; - FuseLauncher.Launch(config.ExecutablePath, forwardedArgs, - message => RecordStartupLog(message, ELogType.Warn)); + FuseLauncher.Launch(config.ExecutablePath, forwardedArgs, LauncherLog.Write); return true; } @@ -132,9 +149,12 @@ namespace WandEnhancer } } + /// Buffers for the UI and mirrors to disk: auto-patch runs headless, so the + /// file is the only copy if the user never opens the window afterwards. private static void RecordStartupLog(string message, ELogType type) { StartupLog.Add(new KeyValuePair(message, type)); + LauncherLog.Write(message, type); } diff --git a/WandEnhancer/WandEnhancer.csproj b/WandEnhancer/WandEnhancer.csproj index 5440d21..82f49d2 100644 --- a/WandEnhancer/WandEnhancer.csproj +++ b/WandEnhancer/WandEnhancer.csproj @@ -67,6 +67,7 @@ +