Skip to content

Commit

Permalink
feat(SyncCheck): Improve status reporting and detect crashes
Browse files Browse the repository at this point in the history
  • Loading branch information
psyGamer committed Nov 30, 2024
1 parent 8cb8380 commit 84f2cc3
Show file tree
Hide file tree
Showing 4 changed files with 59 additions and 33 deletions.
18 changes: 15 additions & 3 deletions CelesteTAS-EverestInterop/Source/EverestInterop/Core.cs
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
using MonoMod.RuntimeDetour;
using TAS.Input.Commands;
using TAS.Module;
using TAS.SyncCheck;
using TAS.Utils;
using GameInput = Celeste.Input;

Expand Down Expand Up @@ -62,8 +63,19 @@ private static void Celeste_Update(On.Celeste.Celeste.orig_Update orig, Celeste.
for (int i = 0; i < loops; i++) {
float oldFreezeTimer = Engine.FreezeTimer;

// Anything happening early on runs in the MInput.Update hook.
orig(self, gameTime);
try {
// Anything happening early on runs in the MInput.Update hook.
orig(self, gameTime);
} catch (Exception ex) {
if (!SyncChecker.Active) {
throw; // Let Everest handle this
}

SyncChecker.ReportCrash(ex);
Manager.DisableRun();
loops = 1;
}

Manager.AdvanceThroughHiddenFrame = false;

if (TasSettings.HideFreezeFrames && oldFreezeTimer > 0f && oldFreezeTimer > Engine.FreezeTimer) {
Expand Down Expand Up @@ -147,4 +159,4 @@ private static void SkipRenderMethod(ILContext il) {
.Emit(OpCodes.Ret)
.MarkLabel(startLabel);
}
}
}
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
using Celeste.Mod;
using System;
using MonoMod.Utils;
using TAS.Module;
Expand All @@ -22,4 +23,4 @@ private static void Load() {
getCurrentHandler = type.GetProperty("CurrentHandler")?.GetGetMethod()?.GetFastDelegate();
}
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,8 @@
using System.Text.Json;
using System.Text.Json.Serialization;

#nullable enable

namespace TAS.SyncCheck;

/// Result data from a sync-check
Expand All @@ -22,8 +24,12 @@ public enum Status {
Crash
}

// Additional information for the desync reason
public readonly record struct WrongTimeInfo(string FilePath, int FileLine, string OldTime, string NewTime);
public readonly record struct AssertFailedInfo(string FilePath, int FileLine, string Actual, string Expected);

/// Sync-check result for a specific file
public readonly record struct Entry(string FilePath, Status Status, string AdditionalInfo);
public readonly record struct Entry(string FilePath, Status Status, string GameInfo, object? AdditionalInfo);

public readonly List<Entry> Entries = [];
public bool Finished = false;
Expand Down
63 changes: 35 additions & 28 deletions CelesteTAS-EverestInterop/Source/SyncCheck/SyncChecker.cs
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,8 @@
using TAS.Module;
using TAS.Utils;

#nullable enable

namespace TAS.SyncCheck;

/// Automatically runs the specified TAS files and reports if they were successful
Expand All @@ -20,9 +22,8 @@ internal static class SyncChecker {
private static readonly Queue<string> fileQueue = [];
private static string resultFile = string.Empty;

private static List<string> wrongTimes = [];
private static bool wasUnsafe = false;
private static bool wasAssert = false;
private static SyncCheckResult.Status currentStatus = SyncCheckResult.Status.Success;
private static object? currentAdditionalInformation = null;

private static SyncCheckResult result = new();

Expand Down Expand Up @@ -56,29 +57,19 @@ public static void ReportRunFinished() {
Logger.Info("CelesteTAS/SyncCheck", $"Finished check for file: '{InputController.StudioTasFilePath}'");

Check failure on line 57 in CelesteTAS-EverestInterop/Source/SyncCheck/SyncChecker.cs

View workflow job for this annotation

GitHub Actions / build-celestetas

'Logger' does not contain a definition for 'Info'

// Check for desyncs
SyncCheckResult.Entry entry;
if (wasUnsafe) {
// Performed unsafe action in safe-mode
entry = new SyncCheckResult.Entry(InputController.StudioTasFilePath, SyncCheckResult.Status.UnsafeAction, GameInfo.ExactStatus);
} else if (wasAssert) {
// Assertion failure
entry = new SyncCheckResult.Entry(InputController.StudioTasFilePath, SyncCheckResult.Status.AssertFailed, GameInfo.ExactStatus);
} else if (Engine.Scene is not (Level { Completed: true } or LevelExit or AreaComplete)) {
if (currentStatus == SyncCheckResult.Status.Success && Engine.Scene is not (Level { Completed: true } or LevelExit or AreaComplete)) {
// TAS did not finish
GameInfo.Update(updateVel: false);
entry = new SyncCheckResult.Entry(InputController.StudioTasFilePath, SyncCheckResult.Status.NotFinished, GameInfo.ExactStatus);
} else if (wrongTimes.Count != 0) {
// TAS finished with wrong time(s)
entry = new SyncCheckResult.Entry(InputController.StudioTasFilePath, SyncCheckResult.Status.WrongTime, string.Join("\n", wrongTimes));
} else {
// No desync
entry = new SyncCheckResult.Entry(InputController.StudioTasFilePath, SyncCheckResult.Status.Success, string.Empty);
currentStatus = SyncCheckResult.Status.NotFinished;
currentAdditionalInformation = null;
}

GameInfo.Update(updateVel: false);
var entry = new SyncCheckResult.Entry(InputController.StudioTasFilePath, currentStatus, GameInfo.ExactStatus, currentAdditionalInformation);

result.Entries.Add(entry);
result.WriteToFile(resultFile);

if (fileQueue.TryDequeue(out string file)) {
if (fileQueue.TryDequeue(out string? file)) {
CheckFile(file);
} else {
// Done with all checks
Expand All @@ -92,19 +83,36 @@ public static void ReportRunFinished() {
/// Indicates that a time command was updated with another time
public static void ReportWrongTime(string filePath, int fileLine, string oldTime, string newTime) {
Logger.Error("CelesteTAS/SyncCheck", $"Detected wrong time in file '{filePath}' line {fileLine}: '{oldTime}' vs '{newTime}'");

Check failure on line 85 in CelesteTAS-EverestInterop/Source/SyncCheck/SyncChecker.cs

View workflow job for this annotation

GitHub Actions / build-celestetas

'Logger' does not contain a definition for 'Error'
wrongTimes.Add($"{filePath}\t{fileLine}\t{oldTime}\t{newTime}");

if (currentStatus != SyncCheckResult.Status.WrongTime) {
currentStatus = SyncCheckResult.Status.WrongTime;
currentAdditionalInformation = new List<SyncCheckResult.WrongTimeInfo>();
}
((List<SyncCheckResult.WrongTimeInfo>)currentAdditionalInformation!).Add(new SyncCheckResult.WrongTimeInfo(filePath, fileLine, oldTime, newTime));
}

/// Indicates that an unsafe action was performed in safe-mode
public static void ReportUnsafeAction() {
Logger.Error("CelesteTAS/SyncCheck", $"Detected unsafe action");

Check failure on line 96 in CelesteTAS-EverestInterop/Source/SyncCheck/SyncChecker.cs

View workflow job for this annotation

GitHub Actions / build-celestetas

'Logger' does not contain a definition for 'Error'
wasUnsafe = true;

currentStatus = SyncCheckResult.Status.UnsafeAction;
currentAdditionalInformation = null;
}

/// Indicates that an Assert-command failed
public static void ReportAssertFailed(string lineText, string filePath, int fileLine, string expected, string actual) {
Logger.Error("CelesteTAS/SyncCheck", $"Detected failed assertion '{lineText}' in file '{filePath}' line {fileLine}: Expected '{expected}', got '{actual}'");

Check failure on line 104 in CelesteTAS-EverestInterop/Source/SyncCheck/SyncChecker.cs

View workflow job for this annotation

GitHub Actions / build-celestetas

'Logger' does not contain a definition for 'Error'
wasAssert = true;

currentStatus = SyncCheckResult.Status.UnsafeAction;
currentAdditionalInformation = new SyncCheckResult.AssertFailedInfo(filePath, fileLine, actual, expected);
}

/// Indicates that a crash happened while sync-checking
public static void ReportCrash(Exception ex) {
Logger.Error("CelesteTAS/SyncCheck", $"Detected a crash: {ex}");

Check failure on line 112 in CelesteTAS-EverestInterop/Source/SyncCheck/SyncChecker.cs

View workflow job for this annotation

GitHub Actions / build-celestetas

'Logger' does not contain a definition for 'Error'

currentStatus = SyncCheckResult.Status.Crash;
currentAdditionalInformation = ex.ToString();
}

[Initialize]
Expand All @@ -120,15 +128,15 @@ private static void On_Celeste_OnSceneTransition(On.Celeste.Celeste.orig_OnScene
orig(self, last, next);

// Wait until game is done loading
if (waitingForLoad && next is Overworld) {
if (waitingForLoad && Active && next is Overworld) {
waitingForLoad = false;

if (string.IsNullOrEmpty(resultFile)) {
Logger.Error("CelesteTAS/SyncCheck", "No result file specified. Aborting sync-check!");

Check failure on line 135 in CelesteTAS-EverestInterop/Source/SyncCheck/SyncChecker.cs

View workflow job for this annotation

GitHub Actions / build-celestetas

'Logger' does not contain a definition for 'Error'
Engine.Instance.Exit();
}

if (fileQueue.TryDequeue(out string file)) {
if (fileQueue.TryDequeue(out string? file)) {
CheckFile(file);
}
}
Expand All @@ -137,9 +145,8 @@ private static void On_Celeste_OnSceneTransition(On.Celeste.Celeste.orig_OnScene
/// Starts executing a TAS for sync-checking
private static void CheckFile(string file) {
// Reset state
wrongTimes.Clear();
wasUnsafe = false;
wasAssert = false;
currentStatus = SyncCheckResult.Status.Success;
currentAdditionalInformation = null;

Logger.Info("CelesteTAS/SyncCheck", $"Starting check for file: '{file}'");

Expand Down

0 comments on commit 84f2cc3

Please sign in to comment.