diff --git a/Assets/Tests/Editor/PressEdgeDiagnosticsMessageFormatterTests.cs b/Assets/Tests/Editor/PressEdgeDiagnosticsMessageFormatterTests.cs new file mode 100644 index 0000000000..e7d09495b1 --- /dev/null +++ b/Assets/Tests/Editor/PressEdgeDiagnosticsMessageFormatterTests.cs @@ -0,0 +1,73 @@ +#nullable enable +using NUnit.Framework; + +using io.github.hatayama.UnityCliLoop.FirstPartyTools; + +namespace io.github.hatayama.UnityCliLoop.Tests.Editor +{ + /// + /// Pure unit tests for the press-edge-miss diagnostic message suffix. + /// + public sealed class PressEdgeDiagnosticsMessageFormatterTests + { + [Test] + public void BuildSuffix_WhenKeyAlreadyPressedBeforeQueue_ReportsNoTransition() + { + // Verifies a pre-existing down state (no edge possible) is reported over other causes. + string suffix = PressEdgeDiagnosticsMessageFormatter.BuildSuffix( + consumedByUpdateType: "Dynamic", + anyDynamicUpdateObserved: true, + keyAlreadyPressedBeforeQueue: true); + + Assert.That(suffix, Does.Contain("already down")); + } + + [Test] + public void BuildSuffix_WhenNotConsumedAndNoDynamicUpdateRan_ReportsNoDynamicUpdate() + { + // Verifies a stalled Dynamic update loop is distinguished from a dropped event. + string suffix = PressEdgeDiagnosticsMessageFormatter.BuildSuffix( + consumedByUpdateType: null, + anyDynamicUpdateObserved: false, + keyAlreadyPressedBeforeQueue: false); + + Assert.That(suffix, Does.Contain("no Dynamic update ran")); + } + + [Test] + public void BuildSuffix_WhenNotConsumedButDynamicUpdatesRan_ReportsDroppedEvent() + { + // Verifies the event-never-consumed case is distinguished from a stalled update loop. + string suffix = PressEdgeDiagnosticsMessageFormatter.BuildSuffix( + consumedByUpdateType: null, + anyDynamicUpdateObserved: true, + keyAlreadyPressedBeforeQueue: false); + + Assert.That(suffix, Does.Contain("not consumed by any recorded")); + } + + [Test] + public void BuildSuffix_WhenConsumedByEditorUpdate_ReportsEditorInvisibility() + { + // Verifies the Editor-update-consumed case names the reason gameplay could not see it. + string suffix = PressEdgeDiagnosticsMessageFormatter.BuildSuffix( + consumedByUpdateType: "Editor", + anyDynamicUpdateObserved: false, + keyAlreadyPressedBeforeQueue: false); + + Assert.That(suffix, Does.Contain("Editor update")); + } + + [Test] + public void BuildSuffix_WhenConsumedByOtherUpdateType_NamesThatUpdateType() + { + // Verifies an unexpected consuming update type (e.g. Fixed) is surfaced by name. + string suffix = PressEdgeDiagnosticsMessageFormatter.BuildSuffix( + consumedByUpdateType: "Fixed", + anyDynamicUpdateObserved: true, + keyAlreadyPressedBeforeQueue: false); + + Assert.That(suffix, Does.Contain("Fixed update")); + } + } +} diff --git a/Assets/Tests/Editor/PressEdgeDiagnosticsMessageFormatterTests.cs.meta b/Assets/Tests/Editor/PressEdgeDiagnosticsMessageFormatterTests.cs.meta new file mode 100644 index 0000000000..03606db46e --- /dev/null +++ b/Assets/Tests/Editor/PressEdgeDiagnosticsMessageFormatterTests.cs.meta @@ -0,0 +1,11 @@ +fileFormatVersion: 2 +guid: c8452ba5be2074cc880fe7a53721c585 +MonoImporter: + externalObjects: {} + serializedVersion: 2 + defaultReferences: [] + executionOrder: 0 + icon: {instanceID: 0} + userData: + assetBundleName: + assetBundleVariant: diff --git a/Packages/src/Editor/FirstPartyTools/Common/InputSystem/PressEdgeDiagnosticsMessageFormatter.cs b/Packages/src/Editor/FirstPartyTools/Common/InputSystem/PressEdgeDiagnosticsMessageFormatter.cs new file mode 100644 index 0000000000..3af3798ff1 --- /dev/null +++ b/Packages/src/Editor/FirstPartyTools/Common/InputSystem/PressEdgeDiagnosticsMessageFormatter.cs @@ -0,0 +1,39 @@ +#nullable enable + +namespace io.github.hatayama.UnityCliLoop.FirstPartyTools +{ + /// + /// Pure formatting of the diagnostic suffix appended to Press/KeyDown responses when the + /// gameplay press edge (wasPressedThisFrame) was not observed. Why: the root cause of an + /// unobserved edge cannot be reproduced on demand (see Round-6 investigation), so instead of + /// a speculative behavior change this records enough context to diagnose the next real + /// occurrence from the response alone. + /// + internal static class PressEdgeDiagnosticsMessageFormatter + { + public static string BuildSuffix( + string? consumedByUpdateType, + bool anyDynamicUpdateObserved, + bool keyAlreadyPressedBeforeQueue) + { + if (keyAlreadyPressedBeforeQueue) + { + return " (key was already down before this action, so no press transition occurred)"; + } + + if (consumedByUpdateType == null) + { + return anyDynamicUpdateObserved + ? " (the key-down event was not consumed by any recorded Input System update, even though Dynamic updates ran during the wait)" + : " (no Dynamic update ran during the wait, so gameplay Update polling never had a chance to observe it)"; + } + + if (consumedByUpdateType == "Editor") + { + return " (the key-down event was consumed during an Editor update, which gameplay Update polling cannot see)"; + } + + return $" (the key-down event was consumed during a {consumedByUpdateType} update, but wasPressedThisFrame was still not observed)"; + } + } +} diff --git a/Packages/src/Editor/FirstPartyTools/Common/InputSystem/PressEdgeDiagnosticsMessageFormatter.cs.meta b/Packages/src/Editor/FirstPartyTools/Common/InputSystem/PressEdgeDiagnosticsMessageFormatter.cs.meta new file mode 100644 index 0000000000..ca59094c5e --- /dev/null +++ b/Packages/src/Editor/FirstPartyTools/Common/InputSystem/PressEdgeDiagnosticsMessageFormatter.cs.meta @@ -0,0 +1,11 @@ +fileFormatVersion: 2 +guid: 8ec0e3d422d1840dda9ee4456187d173 +MonoImporter: + externalObjects: {} + serializedVersion: 2 + defaultReferences: [] + executionOrder: 0 + icon: {instanceID: 0} + userData: + assetBundleName: + assetBundleVariant: diff --git a/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/KeyboardInputActionExecutor.cs b/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/KeyboardInputActionExecutor.cs index 7738046317..d28a0f2b14 100644 --- a/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/KeyboardInputActionExecutor.cs +++ b/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/KeyboardInputActionExecutor.cs @@ -4,6 +4,7 @@ using System.Threading; using System.Threading.Tasks; using UnityEngine.InputSystem; +using UnityEngine.InputSystem.LowLevel; using io.github.hatayama.UnityCliLoop.Runtime; using io.github.hatayama.UnityCliLoop.ToolContracts; @@ -46,19 +47,28 @@ internal static async Task ExecutePress( bool pressWasApplied = false; bool pressEdgeObserved = false; int pressHoldExtendedFrames = 0; + PressEdgeMissDiagnostics edgeMissDiagnostics = new(); InputSimulationWaitOutcome waitOutcome = InputSimulationWaitOutcome.Completed; // The edge must be probed inside gameplay input updates: editor-tick polling can // miss the single frame where wasPressedThisFrame is true, and an editor-update // consumed press is exactly the failure gameplay code cannot see. await InputSystemUpdateHelper.SwitchToMainThreadIfNeeded(ct); - Action pressEdgeMonitor = () => pressEdgeObserved |= IsGameplayPressEdgeVisible(keyboard, key); + Action pressEdgeMonitor = () => + { + pressEdgeObserved |= IsGameplayPressEdgeVisible(keyboard, key); + RecordPressEdgeMissDiagnostics(keyboard, key, edgeMissDiagnostics); + }; InputSystem.onAfterUpdate += pressEdgeMonitor; try { waitOutcome = await InputSystemUpdateHelper.ApplyOnNextConfiguredUpdate( - () => KeyboardKeyState.SetKeyState(keyboard, key, true), + () => + { + edgeMissDiagnostics.KeyAlreadyPressedBeforeQueue = keyboard[key].isPressed; + KeyboardKeyState.SetKeyState(keyboard, key, true); + }, ct).ConfigureAwait(false); if (waitOutcome == InputSimulationWaitOutcome.Completed) { @@ -142,7 +152,11 @@ await KeyboardInputMainThreadCleanup.ReleaseKeyStateIfPossible( else { edgeText = - " (press edge was not observed via wasPressedThisFrame; gameplay polling may have missed it, so retry or verify with a focused log)"; + " (press edge was not observed via wasPressedThisFrame; gameplay polling may have missed it, so retry or verify with a focused log)" + + PressEdgeDiagnosticsMessageFormatter.BuildSuffix( + edgeMissDiagnostics.ConsumedByUpdateType, + edgeMissDiagnostics.AnyDynamicUpdateObserved, + edgeMissDiagnostics.KeyAlreadyPressedBeforeQueue); } return new SimulateKeyboardResponse @@ -152,7 +166,10 @@ await KeyboardInputMainThreadCleanup.ReleaseKeyStateIfPossible( Action = UnityCliLoopKeyboardAction.Press.ToString(), KeyName = keyName, PressEdgeObserved = pressEdgeObserved, - PressHoldExtendedFrames = pressHoldExtendedFrames > 0 ? pressHoldExtendedFrames : null + PressHoldExtendedFrames = pressHoldExtendedFrames > 0 ? pressHoldExtendedFrames : null, + PressEdgeConsumedByUpdateType = pressEdgeObserved ? null : edgeMissDiagnostics.ConsumedByUpdateType, + PressEdgeAnyDynamicUpdateObserved = pressEdgeObserved ? null : edgeMissDiagnostics.AnyDynamicUpdateObserved, + PressEdgeKeyAlreadyPressedBeforeQueue = pressEdgeObserved ? null : edgeMissDiagnostics.KeyAlreadyPressedBeforeQueue }; } @@ -177,16 +194,25 @@ internal static async Task ExecuteKeyDown( bool keyDownApplied = false; bool committed = false; bool pressEdgeObserved = false; + PressEdgeMissDiagnostics edgeMissDiagnostics = new(); InputSimulationWaitOutcome waitOutcome = InputSimulationWaitOutcome.Completed; await InputSystemUpdateHelper.SwitchToMainThreadIfNeeded(ct); - Action keyDownEdgeMonitor = () => pressEdgeObserved |= IsGameplayPressEdgeVisible(keyboard, key); + Action keyDownEdgeMonitor = () => + { + pressEdgeObserved |= IsGameplayPressEdgeVisible(keyboard, key); + RecordPressEdgeMissDiagnostics(keyboard, key, edgeMissDiagnostics); + }; InputSystem.onAfterUpdate += keyDownEdgeMonitor; try { waitOutcome = await InputSystemUpdateHelper.ApplyOnNextConfiguredUpdate( - () => KeyboardKeyState.SetKeyState(keyboard, key, true), + () => + { + edgeMissDiagnostics.KeyAlreadyPressedBeforeQueue = keyboard[key].isPressed; + KeyboardKeyState.SetKeyState(keyboard, key, true); + }, ct).ConfigureAwait(false); if (waitOutcome == InputSimulationWaitOutcome.Completed) { @@ -243,14 +269,21 @@ await KeyboardInputMainThreadCleanup.RollbackHeldKey( string keyDownEdgeText = pressEdgeObserved ? "" - : " (press edge was not observed via wasPressedThisFrame; gameplay polling may have missed it)"; + : " (press edge was not observed via wasPressedThisFrame; gameplay polling may have missed it)" + + PressEdgeDiagnosticsMessageFormatter.BuildSuffix( + edgeMissDiagnostics.ConsumedByUpdateType, + edgeMissDiagnostics.AnyDynamicUpdateObserved, + edgeMissDiagnostics.KeyAlreadyPressedBeforeQueue); return new SimulateKeyboardResponse { Success = true, Message = $"Key '{keyName}' held down{keyDownEdgeText}", Action = UnityCliLoopKeyboardAction.KeyDown.ToString(), KeyName = keyName, - PressEdgeObserved = pressEdgeObserved + PressEdgeObserved = pressEdgeObserved, + PressEdgeConsumedByUpdateType = pressEdgeObserved ? null : edgeMissDiagnostics.ConsumedByUpdateType, + PressEdgeAnyDynamicUpdateObserved = pressEdgeObserved ? null : edgeMissDiagnostics.AnyDynamicUpdateObserved, + PressEdgeKeyAlreadyPressedBeforeQueue = pressEdgeObserved ? null : edgeMissDiagnostics.KeyAlreadyPressedBeforeQueue }; } @@ -320,12 +353,44 @@ await KeyboardInputMainThreadCleanup.ReleaseKeyStateIfPossible( // consumed there never surfaces as wasPressedThisFrame to gameplay Update polling. private static bool IsGameplayPressEdgeVisible(Keyboard keyboard, Key key) { - if (UnityEngine.InputSystem.LowLevel.InputState.currentUpdateType == UnityEngine.InputSystem.LowLevel.InputUpdateType.Editor) + if (InputState.currentUpdateType == InputUpdateType.Editor) { return false; } return keyboard[key].wasPressedThisFrame; } + + // Runs inside InputSystem.onAfterUpdate alongside the edge visibility check above. + // Why: the root cause of an unobserved edge could not be reproduced (see Round-6 + // investigation), so this records which update type (if any) actually saw + // wasPressedThisFrame become true, and whether a Dynamic update ran at all, to diagnose + // the next real occurrence directly from the response instead of guessing. + private static void RecordPressEdgeMissDiagnostics( + Keyboard keyboard, + Key key, + PressEdgeMissDiagnostics diagnostics) + { + InputUpdateType currentUpdateType = InputState.currentUpdateType; + if (currentUpdateType == InputUpdateType.Dynamic) + { + diagnostics.AnyDynamicUpdateObserved = true; + } + + if (diagnostics.ConsumedByUpdateType == null && keyboard[key].wasPressedThisFrame) + { + diagnostics.ConsumedByUpdateType = currentUpdateType.ToString(); + } + } + + // Mutable accumulator for RecordPressEdgeMissDiagnostics, captured by the onAfterUpdate + // monitor lambda. A class (not out/ref locals) so the lambda closure can write to it + // across repeated update callbacks without ref parameters. + private sealed class PressEdgeMissDiagnostics + { + public string? ConsumedByUpdateType; + public bool AnyDynamicUpdateObserved; + public bool KeyAlreadyPressedBeforeQueue; + } } } #endif diff --git a/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/SimulateKeyboardResponse.cs b/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/SimulateKeyboardResponse.cs index d60d6d7062..ec19cb2187 100644 --- a/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/SimulateKeyboardResponse.cs +++ b/Packages/src/Editor/FirstPartyTools/SimulateKeyboard/SimulateKeyboardResponse.cs @@ -26,6 +26,27 @@ public class SimulateKeyboardResponse : UnityCliLoopToolResponse /// public int? PressHoldExtendedFrames { get; set; } + // The following three PressEdge* fields are diagnostics set only when PressEdgeObserved + // is false, to help diagnose the next occurrence without changing Press/KeyDown timing, + // grace, or retry behavior. + + /// + /// Which Input System update type (if any) consumed the key-down event, or null if it + /// was never consumed. + /// + public string? PressEdgeConsumedByUpdateType { get; set; } + + /// + /// Whether any Dynamic update ran while waiting for the press edge to be observed. + /// + public bool? PressEdgeAnyDynamicUpdateObserved { get; set; } + + /// + /// Whether the key was already pressed before this action was queued, meaning no press + /// transition could have occurred. + /// + public bool? PressEdgeKeyAlreadyPressedBeforeQueue { get; set; } + public SimulateKeyboardResponse() { }