diff --git a/src/Spice86.Core/Emulator/VM/EmulationLoop.cs b/src/Spice86.Core/Emulator/VM/EmulationLoop.cs index af113522b1..1a4f701a7f 100644 --- a/src/Spice86.Core/Emulator/VM/EmulationLoop.cs +++ b/src/Spice86.Core/Emulator/VM/EmulationLoop.cs @@ -1,17 +1,14 @@ +namespace Spice86.Core.Emulator.VM; + using Spice86.Core.Emulator.CPU; -using Spice86.Core.Emulator.Devices.DirectMemoryAccess; +using Timer = Spice86.Core.Emulator.Devices.Timer.Timer; using Spice86.Core.Emulator.Errors; using Spice86.Core.Emulator.Function; - -namespace Spice86.Core.Emulator.VM; - using Spice86.Core.Emulator.CPU.CfgCpu; -using Spice86.Core.Emulator.Gdb; using Spice86.Shared.Interfaces; - +using Spice86.Shared.Diagnostics; using System.Diagnostics; -using Timer = Spice86.Core.Emulator.Devices.Timer.Timer; /// /// Runs the emulation loop in a dedicated thread.
@@ -24,8 +21,9 @@ public class EmulationLoop { private readonly State _cpuState; private readonly Timer _timer; private readonly EmulatorBreakpointsManager _emulatorBreakpointsManager; - private readonly Stopwatch _stopwatch; private readonly IPauseHandler _pauseHandler; + private readonly PerformanceMeasurer _performanceMeasurer; + private readonly Stopwatch _stopwatch; /// /// Whether the emulation is paused. @@ -50,6 +48,7 @@ public EmulationLoop(ILoggerService loggerService, FunctionHandler functionHandl _timer = timer; _emulatorBreakpointsManager = emulatorBreakpointsManager; _pauseHandler = pauseHandler; + _performanceMeasurer = new PerformanceMeasurer(); _stopwatch = new(); } @@ -87,14 +86,15 @@ private void StartRunLoop(FunctionHandler functionHandler) { } private void RunLoop() { - _stopwatch.Start(); if (_cpu is CfgCpu cfgCpu) { cfgCpu.SignalEntry(); } + _stopwatch.Start(); while (_cpuState.IsRunning) { _emulatorBreakpointsManager.CheckBreakPoint(); _pauseHandler.WaitIfPaused(); _cpu.ExecuteNext(); + _performanceMeasurer.UpdateValue(_cpuState.Cycles); _timer.Tick(); } _stopwatch.Stop(); @@ -103,13 +103,11 @@ private void RunLoop() { private void OutputPerfStats() { if (_loggerService.IsEnabled(Serilog.Events.LogEventLevel.Warning)) { - long elapsedTimeMilliSeconds = _stopwatch.ElapsedMilliseconds; - long cycles = _cpuState.Cycles; - long cyclesPerSeconds = 0; - if (elapsedTimeMilliSeconds > 0) { - cyclesPerSeconds = (_cpuState.Cycles * 1000) / elapsedTimeMilliSeconds; - } - _loggerService.Warning("Executed {Cycles} instructions in {ElapsedTimeMilliSeconds}ms. {CyclesPerSeconds} Instructions per seconds on average over run.", cycles, elapsedTimeMilliSeconds, cyclesPerSeconds); + long cyclesPerSeconds = _performanceMeasurer.AverageValuePerSecond; + long elapsedTimeInMilliseconds = _stopwatch.ElapsedMilliseconds; + _loggerService.Warning( + "Executed {Cycles} instructions in {ElapsedTimeMilliSeconds}ms. {CyclesPerSeconds} Instructions per seconds on average over run.", + _cpuState.Cycles, elapsedTimeInMilliseconds, cyclesPerSeconds); } } } \ No newline at end of file diff --git a/src/Spice86.Shared/Diagnostics/PerformanceMeasurer.cs b/src/Spice86.Shared/Diagnostics/PerformanceMeasurer.cs index e8d6bad589..548d4291bd 100644 --- a/src/Spice86.Shared/Diagnostics/PerformanceMeasurer.cs +++ b/src/Spice86.Shared/Diagnostics/PerformanceMeasurer.cs @@ -22,7 +22,7 @@ public class PerformanceMeasurer : IPerformanceMeasurer { /// public PerformanceMeasurer() => _lastTimeInMilliseconds = GetCurrentTime(); - private long _firstMeasureTimeInTicks = 0; + private long _firstMeasureTimeInMilliseconds = 0; private const int WindowSizeInSeconds = 30; @@ -31,21 +31,36 @@ public class PerformanceMeasurer : IPerformanceMeasurer { /// public void UpdateValue(long newMeasure) { long newTimeInMilliseconds = GetCurrentTime(); - if (_firstMeasureTimeInTicks == 0) { - _firstMeasureTimeInTicks = newTimeInMilliseconds; - } else if((TimeSpan.FromTicks(newTimeInMilliseconds) - TimeSpan.FromTicks(_firstMeasureTimeInTicks)).TotalSeconds >= WindowSizeInSeconds) { - _firstMeasureTimeInTicks = newTimeInMilliseconds; - _sampledMetricsCount = 0; - AverageValuePerSecond = 0; + if (IsFirstMeasurement()) { + _firstMeasureTimeInMilliseconds = newTimeInMilliseconds; + } else if (IsLastMeasurementExpired(newTimeInMilliseconds)) { + ResetMetrics(newTimeInMilliseconds); } + long millisecondsDelta = newTimeInMilliseconds - _lastTimeInMilliseconds; + if (millisecondsDelta == 0) { + return; + } _lastTimeInMilliseconds = newTimeInMilliseconds; long valueDelta = newMeasure - _measure; _measure = newMeasure; - ValuePerMillisecond = valueDelta / Math.Max(millisecondsDelta, 1); + ValuePerMillisecond = valueDelta / millisecondsDelta; AverageValuePerSecond = ApproxRollingAverage(AverageValuePerSecond, ValuePerSecond, _sampledMetricsCount++); } + private bool IsFirstMeasurement() { + return _firstMeasureTimeInMilliseconds == 0; + } + + private void ResetMetrics(long newTimeInMilliseconds) { + _firstMeasureTimeInMilliseconds = newTimeInMilliseconds; + _sampledMetricsCount = 0; + AverageValuePerSecond = 0; + } + + private bool IsLastMeasurementExpired(long newTimeInMilliseconds) => + newTimeInMilliseconds - _firstMeasureTimeInMilliseconds > WindowSizeInSeconds * 1000; + private static long ApproxRollingAverage(long measureAverage, long valuePerSecond, long sampledMetricsCount) { measureAverage -= measureAverage / Math.Max(sampledMetricsCount, 1); measureAverage += valuePerSecond / Math.Max(sampledMetricsCount, 1); diff --git a/src/Spice86/Spice86DependencyInjection.cs b/src/Spice86/Spice86DependencyInjection.cs index 9113be7b3b..38c54b9b05 100644 --- a/src/Spice86/Spice86DependencyInjection.cs +++ b/src/Spice86/Spice86DependencyInjection.cs @@ -160,7 +160,7 @@ public Spice86DependencyInjection(ILoggerService loggerService, Configuration co emulatorStateSerializer); mainWindowViewModel = new MainWindowViewModel( timer, uiThreadDispatcher, hostStorageProvider, textClipboard, configuration, - loggerService, pauseHandler); + loggerService, pauseHandler, performanceViewModel); } VgaCard vgaCard = new(mainWindowViewModel, vgaRenderer, loggerService); diff --git a/src/Spice86/ViewModels/MainWindowViewModel.cs b/src/Spice86/ViewModels/MainWindowViewModel.cs index 6f902f1410..28fc3fe516 100644 --- a/src/Spice86/ViewModels/MainWindowViewModel.cs +++ b/src/Spice86/ViewModels/MainWindowViewModel.cs @@ -33,6 +33,7 @@ public sealed partial class MainWindowViewModel : ViewModelWithErrorDialog, IGui private readonly AvaloniaKeyScanCodeConverter _avaloniaKeyScanCodeConverter; private readonly IPauseHandler _pauseHandler; private readonly ITimeMultiplier _pit; + private readonly PerformanceViewModel _performanceViewModel; [ObservableProperty] private bool _canUseInternalDebugger; @@ -59,8 +60,9 @@ public sealed partial class MainWindowViewModel : ViewModelWithErrorDialog, IGui public MainWindowViewModel( ITimeMultiplier pit, IUIDispatcher uiDispatcher, IHostStorageProvider hostStorageProvider, ITextClipboard textClipboard, - Configuration configuration, ILoggerService loggerService, IPauseHandler pauseHandler) : base(textClipboard) { + Configuration configuration, ILoggerService loggerService, IPauseHandler pauseHandler, PerformanceViewModel performanceViewModel) : base(textClipboard) { _pit = pit; + _performanceViewModel = performanceViewModel; _avaloniaKeyScanCodeConverter = new AvaloniaKeyScanCodeConverter(); Configuration = configuration; _loggerService = loggerService; @@ -71,8 +73,13 @@ public MainWindowViewModel( _pauseHandler.Resumed += OnResumed; TimeMultiplier = Configuration.TimeMultiplier; CanUseInternalDebugger = configuration.GdbPort is null; + DispatcherTimerStarter.StartNewDispatcherTimer(TimeSpan.FromSeconds(1.0 / 30.0), DispatcherPriority.MaxValue, (_, _) => UpdateCpuInstructionsPerMillisecondsInMainWindowTitle()); } - + + private void UpdateCpuInstructionsPerMillisecondsInMainWindowTitle() { + SetMainTitle(_performanceViewModel.InstructionsPerMillisecond); + } + [RelayCommand] public void SetLogLevelToSilent() => SetLogLevel("Silent"); @@ -228,14 +235,15 @@ public void SetResolution(int width, int height) { [RelayCommand(CanExecute = nameof(IsEmulatorRunning))] private async Task DumpEmulatorStateToFile() { - //TODO: refactor this await _hostStorageProvider.DumpEmulatorStateToFile().ConfigureAwait(false); } [RelayCommand(CanExecute = nameof(CanPause))] public void Pause() => _pauseHandler.RequestPause("Pause button pressed in main window"); - private void SetMainTitle() => MainTitle = $"{nameof(Spice86)} {Configuration.Exe}"; + private void SetMainTitle(double instructionsPerMillisecond) { + MainTitle = $"{nameof(Spice86)} {Configuration.Exe} - cycles/ms: {instructionsPerMillisecond,7:N0}"; + } [ObservableProperty] private string? _mainTitle; @@ -303,7 +311,7 @@ internal void StartEmulator() { _ => "ASM code overrides: none." }; SetLogLevel(Configuration.SilencedLogs ? "Silent" : _loggerService.LogLevelSwitch.MinimumLevel.ToString()); - SetMainTitle(); + SetMainTitle(_performanceViewModel.InstructionsPerMillisecond); StartEmulatorThread(); } diff --git a/src/Spice86/ViewModels/PerformanceViewModel.cs b/src/Spice86/ViewModels/PerformanceViewModel.cs index 9524c87669..5fa54832ad 100644 --- a/src/Spice86/ViewModels/PerformanceViewModel.cs +++ b/src/Spice86/ViewModels/PerformanceViewModel.cs @@ -37,8 +37,12 @@ private void UpdatePerformanceInfo(object? sender, EventArgs e) { InstructionsExecuted = _state.Cycles; _performanceMeasurer.UpdateValue(_state.Cycles); AverageInstructionsPerSecond = _performanceMeasurer.AverageValuePerSecond; + InstructionsPerMillisecond = _performanceMeasurer.ValuePerMillisecond; } + [ObservableProperty] + private double _instructionsPerMillisecond; + [ObservableProperty] private double _instructionsExecuted; }