From aac6ec3d4c4145c808ff7decb79d32900cef7d45 Mon Sep 17 00:00:00 2001 From: pizzaboxer Date: Sat, 12 Oct 2024 17:37:25 +0100 Subject: [PATCH] Improve watcher/failed launch handling Bloxstrap now attempts to identify the log file *when* Roblox launches, then passes it to the watcher It does this so that it can determine if Roblox fails to launch --- Bloxstrap/App.xaml.cs | 2 - Bloxstrap/Bootstrapper.cs | 69 ++++++++++++++++---- Bloxstrap/Integrations/ActivityWatcher.cs | 78 ++++++++++++----------- Bloxstrap/Models/WatcherData.cs | 11 ++++ Bloxstrap/UI/Frontend.cs | 6 +- Bloxstrap/Watcher.cs | 57 +++++++---------- 6 files changed, 132 insertions(+), 91 deletions(-) create mode 100644 Bloxstrap/Models/WatcherData.cs diff --git a/Bloxstrap/App.xaml.cs b/Bloxstrap/App.xaml.cs index 17528f399..ce40e079c 100644 --- a/Bloxstrap/App.xaml.cs +++ b/Bloxstrap/App.xaml.cs @@ -5,8 +5,6 @@ using Microsoft.Win32; -using Bloxstrap.Models.SettingTasks.Base; - namespace Bloxstrap { /// diff --git a/Bloxstrap/Bootstrapper.cs b/Bloxstrap/Bootstrapper.cs index b1a25c228..e9d8609bf 100644 --- a/Bloxstrap/Bootstrapper.cs +++ b/Bloxstrap/Bootstrapper.cs @@ -59,6 +59,8 @@ public class Bootstrapper private bool _mustUpgrade => String.IsNullOrEmpty(AppData.State.VersionGuid) || File.Exists(AppData.LockFilePath) || !File.Exists(AppData.ExecutablePath); private bool _noConnection = false; + private AsyncMutex? _mutex; + private int _appPid = 0; public IBootstrapperDialog? Dialog = null; @@ -191,6 +193,8 @@ public async Task Run() await using var mutex = new AsyncMutex(false, "Bloxstrap-Bootstrapper"); await mutex.AcquireAsync(_cancelTokenSource.Token); + _mutex = mutex; + // reload our configs since they've likely changed by now if (mutexExists) { @@ -230,11 +234,14 @@ public async Task Run() else WindowsRegistry.RegisterPlayer(); - await mutex.ReleaseAsync(); + if (_launchMode != LaunchMode.Player) + await mutex.ReleaseAsync(); if (!App.LaunchSettings.NoLaunchFlag.Active && !_cancelTokenSource.IsCancellationRequested) StartRoblox(); + await mutex.ReleaseAsync(); + Dialog?.CloseBootstrapper(); } @@ -336,12 +343,27 @@ private void StartRoblox() return; } - bool startEventSignalled; + string? logFileName = null; - // TODO: figure out why this is causing roblox to block for some users using (var startEvent = new EventWaitHandle(false, EventResetMode.ManualReset, AppData.StartEvent)) { startEvent.Reset(); + + var logWatcher = new FileSystemWatcher() + { + Path = Path.Combine(Paths.LocalAppData, "Roblox\\logs"), + Filter = "*.log", + EnableRaisingEvents = true + }; + + var logCreatedEvent = new AutoResetEvent(false); + + logWatcher.Created += (_, e) => + { + logWatcher.EnableRaisingEvents = false; + logFileName = e.FullPath; + logCreatedEvent.Set(); + }; // v2.2.0 - byfron will trip if we keep a process handle open for over a minute, so we're doing this now try @@ -358,11 +380,26 @@ private void StartRoblox() App.Logger.WriteLine(LOG_IDENT, $"Started Roblox (PID {_appPid}), waiting for start event"); - startEventSignalled = startEvent.WaitOne(TimeSpan.FromSeconds(5)); - } + if (startEvent.WaitOne(TimeSpan.FromSeconds(5))) + App.Logger.WriteLine(LOG_IDENT, "Start event signalled"); + else + App.Logger.WriteLine(LOG_IDENT, "Start event not signalled, implying successful launch"); - if (startEventSignalled) - App.Logger.WriteLine(LOG_IDENT, "Start event signalled"); + logCreatedEvent.WaitOne(TimeSpan.FromSeconds(5)); + + if (String.IsNullOrEmpty(logFileName)) + { + App.Logger.WriteLine(LOG_IDENT, "Unable to identify log file"); + Frontend.ShowPlayerErrorDialog(); + return; + } + else + { + App.Logger.WriteLine(LOG_IDENT, $"Got log file as {logFileName}"); + } + + _mutex?.ReleaseAsync(); + } if (IsStudioLaunch) return; @@ -391,23 +428,27 @@ private void StartRoblox() catch (Exception ex) { App.Logger.WriteLine(LOG_IDENT, $"Failed to launch integration '{integration.Name}'!"); - App.Logger.WriteLine(LOG_IDENT, $"{ex.Message}"); + App.Logger.WriteLine(LOG_IDENT, ex.Message); } if (integration.AutoClose && pid != 0) autoclosePids.Add(pid); } - string argPids = _appPid.ToString(); - - if (autoclosePids.Any()) - argPids += $";{String.Join(',', autoclosePids)}"; - if (App.Settings.Prop.EnableActivityTracking || App.LaunchSettings.TestModeFlag.Active || autoclosePids.Any()) { using var ipl = new InterProcessLock("Watcher", TimeSpan.FromSeconds(5)); - string args = $"-watcher \"{argPids}\""; + var watcherData = new WatcherData + { + ProcessId = _appPid, + LogFile = logFileName, + AutoclosePids = autoclosePids + }; + + string watcherDataArg = Convert.ToBase64String(Encoding.UTF8.GetBytes(JsonSerializer.Serialize(watcherData))); + + string args = $"-watcher \"{watcherDataArg}\""; if (App.LaunchSettings.TestModeFlag.Active) args += " -testmode"; diff --git a/Bloxstrap/Integrations/ActivityWatcher.cs b/Bloxstrap/Integrations/ActivityWatcher.cs index 1ca18d300..2e0483af0 100644 --- a/Bloxstrap/Integrations/ActivityWatcher.cs +++ b/Bloxstrap/Integrations/ActivityWatcher.cs @@ -51,6 +51,12 @@ public class ActivityWatcher : IDisposable public bool IsDisposed = false; + public ActivityWatcher(string? logFile = null) + { + if (!String.IsNullOrEmpty(logFile)) + LogLocation = logFile; + } + public async void Start() { const string LOG_IDENT = "ActivityWatcher::Start"; @@ -65,58 +71,58 @@ public async void Start() // - check for leaves/disconnects with 'Time to disconnect replication data: {{TIME}}' entry // // we'll tail the log file continuously, monitoring for any log entries that we need to determine the current game activity + + FileInfo logFileInfo; - string logDirectory = Path.Combine(Paths.LocalAppData, "Roblox\\logs"); + if (String.IsNullOrEmpty(LogLocation)) + { + string logDirectory = Path.Combine(Paths.LocalAppData, "Roblox\\logs"); - if (!Directory.Exists(logDirectory)) - return; + if (!Directory.Exists(logDirectory)) + return; - FileInfo logFileInfo; + // we need to make sure we're fetching the absolute latest log file + // if roblox doesn't start quickly enough, we can wind up fetching the previous log file + // good rule of thumb is to find a log file that was created in the last 15 seconds or so + + App.Logger.WriteLine(LOG_IDENT, "Opening Roblox log file..."); - // we need to make sure we're fetching the absolute latest log file - // if roblox doesn't start quickly enough, we can wind up fetching the previous log file - // good rule of thumb is to find a log file that was created in the last 15 seconds or so + while (true) + { + logFileInfo = new DirectoryInfo(logDirectory) + .GetFiles() + .Where(x => x.Name.Contains("Player", StringComparison.OrdinalIgnoreCase) && x.CreationTime <= DateTime.Now) + .OrderByDescending(x => x.CreationTime) + .First(); - App.Logger.WriteLine(LOG_IDENT, "Opening Roblox log file..."); + if (logFileInfo.CreationTime.AddSeconds(15) > DateTime.Now) + break; - while (true) - { - logFileInfo = new DirectoryInfo(logDirectory) - .GetFiles() - .Where(x => x.Name.Contains("Player", StringComparison.OrdinalIgnoreCase) && x.CreationTime <= DateTime.Now) - .OrderByDescending(x => x.CreationTime) - .First(); + App.Logger.WriteLine(LOG_IDENT, $"Could not find recent enough log file, waiting... (newest is {logFileInfo.Name})"); + await Task.Delay(1000); + } - if (logFileInfo.CreationTime.AddSeconds(15) > DateTime.Now) - break; + OnLogOpen?.Invoke(this, EventArgs.Empty); - App.Logger.WriteLine(LOG_IDENT, $"Could not find recent enough log file, waiting... (newest is {logFileInfo.Name})"); - await Task.Delay(1000); + LogLocation = logFileInfo.FullName; + } + else + { + logFileInfo = new FileInfo(LogLocation); } - OnLogOpen?.Invoke(this, EventArgs.Empty); + var logFileStream = logFileInfo.Open(FileMode.Open, FileAccess.Read, FileShare.ReadWrite); - LogLocation = logFileInfo.FullName; - FileStream logFileStream = logFileInfo.Open(FileMode.Open, FileAccess.Read, FileShare.ReadWrite); App.Logger.WriteLine(LOG_IDENT, $"Opened {LogLocation}"); - var logUpdatedEvent = new AutoResetEvent(false); - var logWatcher = new FileSystemWatcher() - { - Path = logDirectory, - Filter = Path.GetFileName(logFileInfo.FullName), - EnableRaisingEvents = true - }; - logWatcher.Changed += (s, e) => logUpdatedEvent.Set(); - - using var sr = new StreamReader(logFileStream); + using var streamReader = new StreamReader(logFileStream); while (!IsDisposed) { - string? log = await sr.ReadLineAsync(); + string? log = await streamReader.ReadLineAsync(); if (log is null) - logUpdatedEvent.WaitOne(250); + await Task.Delay(1000); else ReadLogEntry(log); } @@ -265,7 +271,7 @@ private void ReadLogEntry(string entry) InGame = true; Data.TimeJoined = DateTime.Now; - OnGameJoin?.Invoke(this, new EventArgs()); + OnGameJoin?.Invoke(this, EventArgs.Empty); } } else if (InGame && Data.PlaceId != 0) @@ -282,7 +288,7 @@ private void ReadLogEntry(string entry) InGame = false; Data = new(); - OnGameLeave?.Invoke(this, new EventArgs()); + OnGameLeave?.Invoke(this, EventArgs.Empty); } else if (entry.Contains(GameTeleportingEntry)) { diff --git a/Bloxstrap/Models/WatcherData.cs b/Bloxstrap/Models/WatcherData.cs new file mode 100644 index 000000000..f81eb32a0 --- /dev/null +++ b/Bloxstrap/Models/WatcherData.cs @@ -0,0 +1,11 @@ +namespace Bloxstrap.Models +{ + internal class WatcherData + { + public int ProcessId { get; set; } + + public string? LogFile { get; set; } + + public List? AutoclosePids { get; set; } + } +} diff --git a/Bloxstrap/UI/Frontend.cs b/Bloxstrap/UI/Frontend.cs index 21cca14fc..108d455fb 100644 --- a/Bloxstrap/UI/Frontend.cs +++ b/Bloxstrap/UI/Frontend.cs @@ -2,9 +2,6 @@ using Bloxstrap.UI.Elements.Bootstrapper; using Bloxstrap.UI.Elements.Dialogs; -using Bloxstrap.UI.Elements.Settings; -using Bloxstrap.UI.Elements.Installer; -using System.Drawing; namespace Bloxstrap.UI { @@ -31,7 +28,8 @@ public static void ShowPlayerErrorDialog(bool crash = false) topLine = Strings.Dialog_PlayerError_Crash; ShowMessageBox($"{topLine}\n\n{Strings.Dialog_PlayerError_HelpInformation}", MessageBoxImage.Error); - Utilities.ShellExecute($"https://github.com/{App.ProjectRepository}/wiki/Roblox-crashes-or-does-not-launch"); + + // Utilities.ShellExecute($"https://github.com/{App.ProjectRepository}/wiki/Roblox-crashes-or-does-not-launch"); } public static void ShowExceptionDialog(Exception exception) diff --git a/Bloxstrap/Watcher.cs b/Bloxstrap/Watcher.cs index ae67f8bd9..660d5d41a 100644 --- a/Bloxstrap/Watcher.cs +++ b/Bloxstrap/Watcher.cs @@ -1,15 +1,14 @@ using Bloxstrap.Integrations; +using Bloxstrap.Models; namespace Bloxstrap { public class Watcher : IDisposable { - private int _gameClientPid = 0; - private readonly InterProcessLock _lock = new("Watcher"); - private readonly List _autoclosePids = new(); - + private readonly WatcherData? _watcherData; + private readonly NotifyIconWrapper? _notifyIcon; public readonly ActivityWatcher? ActivityWatcher; @@ -26,53 +25,37 @@ public Watcher() return; } - string? watcherData = App.LaunchSettings.WatcherFlag.Data; + string? watcherDataArg = App.LaunchSettings.WatcherFlag.Data; #if DEBUG - if (String.IsNullOrEmpty(watcherData)) + if (String.IsNullOrEmpty(watcherDataArg)) { string path = Path.Combine(Paths.Roblox, "Player", "RobloxPlayerBeta.exe"); using var gameClientProcess = Process.Start(path); - _gameClientPid = gameClientProcess.Id; + + _watcherData = new() { ProcessId = gameClientProcess.Id }; } #else - if (String.IsNullOrEmpty(watcherData)) + if (String.IsNullOrEmpty(watcherDataArg)) throw new Exception("Watcher data not specified"); #endif - if (!String.IsNullOrEmpty(watcherData) && _gameClientPid == 0) - { - var split = watcherData.Split(';'); - - if (split.Length == 0) - _ = int.TryParse(watcherData, out _gameClientPid); - - if (split.Length >= 1) - _ = int.TryParse(split[0], out _gameClientPid); + if (!String.IsNullOrEmpty(watcherDataArg)) + _watcherData = JsonSerializer.Deserialize(Encoding.UTF8.GetString(Convert.FromBase64String(watcherDataArg))); - if (split.Length >= 2) - { - foreach (string strPid in split[1].Split(',')) - { - if (int.TryParse(strPid, out int pid) && pid != 0) - _autoclosePids.Add(pid); - } - } - } - - if (_gameClientPid == 0) + if (_watcherData is null) throw new Exception("Watcher data is invalid"); if (App.Settings.Prop.EnableActivityTracking) { - ActivityWatcher = new(); + ActivityWatcher = new(_watcherData.LogFile); if (App.Settings.Prop.UseDisableAppPatch) { ActivityWatcher.OnAppClose += delegate { App.Logger.WriteLine(LOG_IDENT, "Received desktop app exit, closing Roblox"); - using var process = Process.GetProcessById(_gameClientPid); + using var process = Process.GetProcessById(_watcherData.ProcessId); process.CloseMainWindow(); }; } @@ -84,11 +67,12 @@ public Watcher() _notifyIcon = new(this); } - public void KillRobloxProcess() => CloseProcess(_gameClientPid, true); + public void KillRobloxProcess() => CloseProcess(_watcherData!.ProcessId, true); public void CloseProcess(int pid, bool force = false) { const string LOG_IDENT = "Watcher::CloseProcess"; + try { using var process = Process.GetProcessById(pid); @@ -115,16 +99,19 @@ public void CloseProcess(int pid, bool force = false) public async Task Run() { - if (!_lock.IsAcquired) + if (!_lock.IsAcquired || _watcherData is null) return; ActivityWatcher?.Start(); - while (Utilities.GetProcessesSafe().Any(x => x.Id == _gameClientPid)) + while (Utilities.GetProcessesSafe().Any(x => x.Id == _watcherData.ProcessId)) await Task.Delay(1000); - foreach (int pid in _autoclosePids) - CloseProcess(pid); + if (_watcherData.AutoclosePids is not null) + { + foreach (int pid in _watcherData.AutoclosePids) + CloseProcess(pid); + } if (App.LaunchSettings.TestModeFlag.Active) Process.Start(Paths.Process, "-settings -testmode");