CHANGE: Improve error logging when events get discarded (ISXB-691) (#1929)

* Check event processing after raised error

Improves existing test to make sure a "full" even buffer has in fact discarded events and that they are not processed in the next update

* Add total bytes processed per device in error message

* Fix test

* Update CHANGELOG.md

* Fix formatting

* Move error check to end of while loop

Addresses issues where the warning is not shown even though the bytes of events processed exceed the limit. This turns the check more rigorous.

* Improve string manipulation

Author: jfreire-unity

Assets/Tests/InputSystem/CoreTests_Events.cs

@@ -2365,29 +2365,44 @@ public IEnumerator Events_CanTestInputDistributedOverFrames()
     [Category("Events")]
     public void Events_MaximumEventLoadPerUpdateIsLimited()
     {
-        // Default setting is 5MB.
+        // Default limit setting is 5MB.
         Assert.That(InputSystem.settings.maxEventBytesPerUpdate, Is.EqualTo(5 * 1024 * 1024));
 
+        // Limit the maximum events to be processed per update to 2 Mouse state events.
         InputSystem.settings.maxEventBytesPerUpdate = StateEvent.GetEventSizeWithPayload<MouseState>() * 2;
 
         var mouse = InputSystem.AddDevice<Mouse>();
 
+        // Queue 3 events, where the 3rd one will raise a log error.
+        // Only 2 events from 3 should be processed.
         InputSystem.QueueStateEvent(mouse, new MouseState().WithButton(MouseButton.Left));
         InputSystem.QueueStateEvent(mouse, new MouseState().WithButton(MouseButton.Right));
         InputSystem.QueueStateEvent(mouse, new MouseState().WithButton(MouseButton.Middle));
 
         var eventCount = 0;
         InputSystem.onEvent += (eventPtr, device) => ++ eventCount;
 
+        var totalProcessedMouseStateEventBytes = InputSystem.settings.maxEventBytesPerUpdate;
         LogAssert.Expect(LogType.Error, "Exceeded budget for maximum input event throughput per InputSystem.Update(). Discarding remaining events. "
-            + "Increase InputSystem.settings.maxEventBytesPerUpdate or set it to 0 to remove the limit.");
+            + "Increase InputSystem.settings.maxEventBytesPerUpdate or set it to 0 to remove the limit.\n"
+            + "Total events processed by devices in last update call:\n"
+            + $" - {totalProcessedMouseStateEventBytes} bytes processed by Mouse:/Mouse\n");
 
         InputSystem.Update();
 
         Assert.That(eventCount, Is.EqualTo(2));
         Assert.That(mouse.rightButton.isPressed, Is.True);
         Assert.That(mouse.middleButton.isPressed, Is.False);
 
+        // Queue 1 event after error has been raised
+        InputSystem.QueueStateEvent(mouse, new MouseState().WithButton(MouseButton.Right, false));
+        InputSystem.Update();
+
+        // Check that we have only processed the new event.
+        // Confirms that the 3rd event setting MouseButton.middle was discarded.
+        Assert.That(eventCount, Is.EqualTo(3));
+        Assert.That(mouse.rightButton.isPressed, Is.False);
+
         eventCount = 0;
 
         // Disable the limit.

Packages/com.unity.inputsystem/CHANGELOG.md

@@ -20,6 +20,11 @@ however, it has to be formatted properly to pass verification tests.
 - Fixed Scheme Name in Control Scheme editor menu that gets reset when editing devices [ISXB-763](https://issuetracker.unity3d.com/product/unity/issues/guid/ISXB-763).
 - Fixed an issue where `InputActionAsset.FindAction(string, bool)` would throw `System.NullReferenceException` instead of returning `null` if searching for a non-existent action with an explicit action path and using `throwIfNotFound: false`, e.g. searching for "Map/Action" when `InputActionMap` "Map" exists but no `InputAction` named "Action" exists within that map [ISXB-895](https://issuetracker.unity3d.com/product/unity/issues/guid/ISXB-895).
 
+## Added
+- Added additional device information when logging the error due to exceeding the maximum number of events processed
+  set by `InputSystem.settings.maxEventsBytesPerUpdate`. This additional information is available in development builds
+  only.
+
 ## [1.8.2] - 2024-04-29
 
 ### Added

Packages/com.unity.inputsystem/InputSystem/Devices/InputDevice.cs

@@ -672,7 +672,10 @@ internal bool disabledWhileInBackground
         internal DeviceFlags m_DeviceFlags;
         internal int m_DeviceId;
         internal int m_ParticipantId;
-        internal int m_DeviceIndex; // Index in InputManager.m_Devices.
+        // Index in InputManager.m_Devices.
+        internal int m_DeviceIndex;
+        // Amount of bytes processed in the current update step. Used only for logging purposes.
+        internal uint m_CurrentProcessedEventBytesOnUpdate;
         internal InputDeviceDescription m_Description;
 
         /// <summary>

Packages/com.unity.inputsystem/InputSystem/InputManager.cs

@@ -2,6 +2,7 @@
 using System.Collections.Generic;
 using System.Diagnostics;
 using System.Linq;
+using System.Text;
 using Unity.Collections;
 using UnityEngine.InputSystem.Composites;
 using UnityEngine.InputSystem.Controls;
@@ -3062,15 +3063,6 @@ private unsafe void OnUpdate(InputUpdateType updateType, ref InputEventBuffer ev
                 // Handle events.
                 while (m_InputEventStream.remainingEventCount > 0)
                 {
-                    if (m_Settings.maxEventBytesPerUpdate > 0 &&
-                        totalEventBytesProcessed >= m_Settings.maxEventBytesPerUpdate)
-                    {
-                        Debug.LogError(
-                            "Exceeded budget for maximum input event throughput per InputSystem.Update(). Discarding remaining events. "
-                            + "Increase InputSystem.settings.maxEventBytesPerUpdate or set it to 0 to remove the limit.");
-                        break;
-                    }
-
                     InputDevice device = null;
                     var currentEventReadPtr = m_InputEventStream.currentEventPtr;
 
@@ -3382,6 +3374,8 @@ private unsafe void OnUpdate(InputUpdateType updateType, ref InputEventBuffer ev
 
                             totalEventBytesProcessed += eventPtr.sizeInBytes;
 
+                            device.m_CurrentProcessedEventBytesOnUpdate += eventPtr.sizeInBytes;
+
                             // Update timestamp on device.
                             // NOTE: We do this here and not in UpdateState() so that InputState.Change() will *NOT* change timestamps.
                             //       Only events should. If running play mode updates in editor, we want to defer to the play mode
@@ -3464,12 +3458,18 @@ private unsafe void OnUpdate(InputUpdateType updateType, ref InputEventBuffer ev
                     }
 
                     m_InputEventStream.Advance(leaveEventInBuffer: false);
+
+                    // Discard events in case the maximum event bytes per update has been exceeded
+                    if (AreMaximumEventBytesPerUpdateExceeded(totalEventBytesProcessed))
+                        break;
                 }
 
                 m_Metrics.totalEventProcessingTime +=
                     ((double)(Stopwatch.GetTimestamp() - processingStartTime)) / Stopwatch.Frequency;
                 m_Metrics.totalEventLagTime += totalEventLag;
 
+                ResetCurrentProcessedEventBytesForDevices();
+
                 m_InputEventStream.Close(ref eventBuffer);
             }
             catch (Exception)
@@ -3493,6 +3493,58 @@ private unsafe void OnUpdate(InputUpdateType updateType, ref InputEventBuffer ev
             m_CurrentUpdate = default;
         }
 
+        bool AreMaximumEventBytesPerUpdateExceeded(uint totalEventBytesProcessed)
+        {
+            if (m_Settings.maxEventBytesPerUpdate > 0 &&
+                totalEventBytesProcessed >= m_Settings.maxEventBytesPerUpdate)
+            {
+                var eventsProcessedByDeviceLog = String.Empty;
+                // Only log the events processed by devices in last update call if we are in debug mode.
+                // This is to avoid the slightest overhead in release builds of having to iterate over all devices and
+                // reset the byte count, by the end of every update call with ResetCurrentProcessedEventBytesForDevices().
+                if (Debug.isDebugBuild)
+                    eventsProcessedByDeviceLog = $"Total events processed by devices in last update call:\n{MakeStringWithEventsProcessedByDevice()}";
+
+                Debug.LogError(
+                    "Exceeded budget for maximum input event throughput per InputSystem.Update(). Discarding remaining events. "
+                    + "Increase InputSystem.settings.maxEventBytesPerUpdate or set it to 0 to remove the limit.\n"
+                    + eventsProcessedByDeviceLog);
+
+                return true;
+            }
+
+            return false;
+        }
+
+        private string MakeStringWithEventsProcessedByDevice()
+        {
+            var eventsProcessedByDeviceLog = new StringBuilder();
+            for (int i = 0; i < m_DevicesCount; i++)
+            {
+                var deviceToLog = devices[i];
+                if (deviceToLog != null && deviceToLog.m_CurrentProcessedEventBytesOnUpdate > 0)
+                    eventsProcessedByDeviceLog.Append($" - {deviceToLog.m_CurrentProcessedEventBytesOnUpdate} bytes processed by {deviceToLog}\n");
+            }
+            return eventsProcessedByDeviceLog.ToString();
+        }
+
+        // Reset the number of bytes processed by devices in the current update, for debug builds.
+        // This is to avoid the slightest overhead in release builds of having to iterate over all devices connected.
+        private void ResetCurrentProcessedEventBytesForDevices()
+        {
+            if (Debug.isDebugBuild)
+            {
+                for (var i = 0; i < m_DevicesCount; i++)
+                {
+                    var device = m_Devices[i];
+                    if (device != null && device.m_CurrentProcessedEventBytesOnUpdate > 0)
+                    {
+                        device.m_CurrentProcessedEventBytesOnUpdate = 0;
+                    }
+                }
+            }
+        }
+
         // Only do this check in editor in hope that it will be sufficient to catch any misuse during development.
         [Conditional("UNITY_EDITOR")]
         void CheckAllDevicesOptimizedControlsHaveValidState()