From d9d1aeaef9f3233eecc757031be6d532db3af42e Mon Sep 17 00:00:00 2001 From: kostyaff Date: Sat, 11 Jul 2026 11:54:15 +0300 Subject: [PATCH] [logging] Migrate CpuDispatcher, SharpEmuRuntime, PhysicalVirtualMemory to SharpEmuLog (#51) Replaces 34 Console.Error.WriteLine call sites across 3 Core files with structured SharpEmuLog calls (Debug/Info/Warning/Error/Critical). CpuDispatcher.cs (10 sites): - DispatchEntry/DispatchModuleInitializer START and entry-point logs -> Debug - FATAL EXCEPTION catch blocks -> Critical (with exception object) - Native backend FAILED -> Error SharpEmuRuntime.cs (23 sites): - Loading/Entry/Dispatching/DispatchEntry returned -> Info - Module load/registered/preload summary -> Info - Initializer dispatch failed/module start failed -> Error - Imported data unresolved -> Warning, write-failed -> Error - Import stub conflict -> Warning - Trace-level rebind logs -> Debug PhysicalVirtualMemory.cs (1 site): - TraceVmem helper -> Log.Debug (SHARPEMU_LOG_VMEM env gate preserved) Build: 0 errors, 0 warnings Co-authored-by: Hermes Atlas --- src/SharpEmu.Core/Cpu/CpuDispatcher.cs | 21 +++--- .../Memory/PhysicalVirtualMemory.cs | 5 +- src/SharpEmu.Core/Runtime/SharpEmuRuntime.cs | 73 ++++++++++--------- 3 files changed, 53 insertions(+), 46 deletions(-) diff --git a/src/SharpEmu.Core/Cpu/CpuDispatcher.cs b/src/SharpEmu.Core/Cpu/CpuDispatcher.cs index 0fd08c5..7bdc543 100644 --- a/src/SharpEmu.Core/Cpu/CpuDispatcher.cs +++ b/src/SharpEmu.Core/Cpu/CpuDispatcher.cs @@ -7,11 +7,14 @@ using SharpEmu.Core.Cpu.Native; using SharpEmu.Core.Loader; using SharpEmu.Core.Memory; using SharpEmu.HLE; +using SharpEmu.Logging; namespace SharpEmu.Core.Cpu; public sealed class CpuDispatcher : ICpuDispatcher, IDisposable { + private static readonly SharpEmuLogger Log = SharpEmuLog.For("Dispatcher"); + private enum EntryFrameKind { ProcessEntry, @@ -80,8 +83,8 @@ public sealed class CpuDispatcher : ICpuDispatcher, IDisposable string processImageName = "eboot.bin", CpuExecutionOptions executionOptions = default) { - Console.Error.WriteLine("[DISPATCHER] === DispatchEntry START ==="); - Console.Error.WriteLine($"[DISPATCHER] entryPoint=0x{entryPoint:X16}, generation={generation}"); + Log.Debug("=== DispatchEntry START ==="); + Log.Debug($"entryPoint=0x{entryPoint:X16}, generation={generation}"); try { @@ -89,8 +92,7 @@ public sealed class CpuDispatcher : ICpuDispatcher, IDisposable } catch (Exception ex) { - Console.Error.WriteLine($"[DISPATCHER] FATAL EXCEPTION in DispatchEntry: {ex.GetType().Name}: {ex.Message}"); - Console.Error.WriteLine($"[DISPATCHER] Stack trace: {ex.StackTrace}"); + Log.Critical($"FATAL EXCEPTION in DispatchEntry: {ex.GetType().Name}: {ex.Message}", ex); throw; } } @@ -103,8 +105,8 @@ public sealed class CpuDispatcher : ICpuDispatcher, IDisposable string moduleName = "module", CpuExecutionOptions executionOptions = default) { - Console.Error.WriteLine("[DISPATCHER] === DispatchModuleInitializer START ==="); - Console.Error.WriteLine($"[DISPATCHER] moduleInit=0x{entryPoint:X16}, generation={generation}, module={moduleName}"); + Log.Debug("=== DispatchModuleInitializer START ==="); + Log.Debug($"moduleInit=0x{entryPoint:X16}, generation={generation}, module={moduleName}"); try { @@ -119,8 +121,7 @@ public sealed class CpuDispatcher : ICpuDispatcher, IDisposable } catch (Exception ex) { - Console.Error.WriteLine($"[DISPATCHER] FATAL EXCEPTION in DispatchModuleInitializer: {ex.GetType().Name}: {ex.Message}"); - Console.Error.WriteLine($"[DISPATCHER] Stack trace: {ex.StackTrace}"); + Log.Critical($"FATAL EXCEPTION in DispatchModuleInitializer: {ex.GetType().Name}: {ex.Message}", ex); throw; } } @@ -134,7 +135,7 @@ public sealed class CpuDispatcher : ICpuDispatcher, IDisposable CpuExecutionOptions executionOptions = default, EntryFrameKind frameKind = EntryFrameKind.ProcessEntry) { - Console.Error.WriteLine("[DISPATCHER] DispatchEntryCore STARTING..."); + Log.Debug("DispatchEntryCore STARTING..."); LastEntryPoint = entryPoint; LastTrapInfo = null; @@ -306,7 +307,7 @@ public sealed class CpuDispatcher : ICpuDispatcher, IDisposable LastMilestoneLog, Environment.NewLine, $"CpuEngine native-only failed: {backendError}"); - Console.Error.WriteLine($"[DISPATCHER] Native backend FAILED: {backendError}"); + Log.Error($"Native backend FAILED: {backendError}"); return FailEarly( OrbisGen2Result.ORBIS_GEN2_ERROR_NOT_IMPLEMENTED, CpuExitReason.NativeBackendUnavailable); diff --git a/src/SharpEmu.Core/Memory/PhysicalVirtualMemory.cs b/src/SharpEmu.Core/Memory/PhysicalVirtualMemory.cs index 0a15ae1..3170d19 100644 --- a/src/SharpEmu.Core/Memory/PhysicalVirtualMemory.cs +++ b/src/SharpEmu.Core/Memory/PhysicalVirtualMemory.cs @@ -4,11 +4,14 @@ using System.Runtime.InteropServices; using SharpEmu.Core.Loader; using SharpEmu.HLE; +using SharpEmu.Logging; namespace SharpEmu.Core.Memory; public sealed unsafe class PhysicalVirtualMemory : IVirtualMemory, IGuestMemoryAllocator, IDisposable { + private static readonly SharpEmuLogger Log = SharpEmuLog.For("VMEM"); + private readonly ReaderWriterLockSlim _gate = new(LockRecursionPolicy.SupportsRecursion); private readonly object _guestAllocationGate = new(); private readonly object _allocationSearchHintGate = new(); @@ -1052,7 +1055,7 @@ public sealed unsafe class PhysicalVirtualMemory : IVirtualMemory, IGuestMemoryA return; } - Console.Error.WriteLine($"[VMEM] {message}"); + Log.Debug(message); } public void Dispose() diff --git a/src/SharpEmu.Core/Runtime/SharpEmuRuntime.cs b/src/SharpEmu.Core/Runtime/SharpEmuRuntime.cs index eab36fa..a0fd5fc 100644 --- a/src/SharpEmu.Core/Runtime/SharpEmuRuntime.cs +++ b/src/SharpEmu.Core/Runtime/SharpEmuRuntime.cs @@ -11,6 +11,7 @@ using SharpEmu.Libs.VideoOut; using SharpEmu.Libs.Kernel; using SharpEmu.Libs.AppContent; using SharpEmu.Libs.SaveData; +using SharpEmu.Logging; using System.Buffers.Binary; using System.Collections.Generic; using System.Linq; @@ -20,6 +21,8 @@ namespace SharpEmu.Core.Runtime; public sealed class SharpEmuRuntime : ISharpEmuRuntime { + private static readonly SharpEmuLogger Log = SharpEmuLog.For("Runtime"); + private readonly record struct LoadedModuleImage(string Path, SelfImage Image); private static readonly HashSet PreloadSkipModules = new(StringComparer.OrdinalIgnoreCase) @@ -128,7 +131,7 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime { var normalizedEbootPath = Path.GetFullPath(ebootPath); using var app0Binding = BindApp0Root(normalizedEbootPath); - Console.Error.WriteLine($"[RUNTIME] Loading: {ebootPath}"); + Log.Info($"Loading: {ebootPath}"); LastExecutionDiagnostics = null; LastExecutionTrace = null; LastSessionSummary = null; @@ -140,7 +143,7 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime SaveDataExports.ConfigureApplicationInfo(image.TitleId); RegisterLoadedModule(normalizedEbootPath, image, isMain: true, isSystemModule: false); KernelRuntimeCompatExports.ConfigureProcessProcParamAddress(image.ProcParamAddress); - Console.Error.WriteLine($"[RUNTIME] Entry: 0x{image.EntryPoint:X16}"); + Log.Info($"Entry: 0x{image.EntryPoint:X16}"); var generation = image.ElfHeader.AbiVersion == 2 ? Generation.Gen5 : Generation.Gen4; var activeImportStubs = new Dictionary(image.ImportStubs); var activeRuntimeSymbols = new Dictionary(image.RuntimeSymbols, StringComparer.Ordinal); @@ -163,7 +166,7 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime processImageName); if (initializerResult is { } failedInitializerResult) { - Console.Error.WriteLine($"[RUNTIME] Initializer dispatch failed: {failedInitializerResult}"); + Log.Error($"Initializer dispatch failed: {failedInitializerResult}"); LastExecutionTrace = _cpuDispatcher.LastImportResolutionTrace; LastMilestoneLog = _cpuDispatcher.LastMilestoneLog; LastSessionSummary = BuildSessionSummary(_cpuDispatcher.LastSessionSummary); @@ -171,8 +174,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime return failedInitializerResult; } - Console.Error.WriteLine($"[RUNTIME] Dispatching, gen: {generation}"); - Console.Error.WriteLine($"[RUNTIME] About to call DispatchEntry with entryPoint=0x{image.EntryPoint:X16}"); + Log.Info($"Dispatching, gen: {generation}"); + Log.Debug($"About to call DispatchEntry with entryPoint=0x{image.EntryPoint:X16}"); var result = _cpuDispatcher.DispatchEntry( image.EntryPoint, @@ -182,8 +185,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime processImageName, _cpuExecutionOptions); - Console.Error.WriteLine($"[RUNTIME] DispatchEntry returned: {result}"); - Console.Error.WriteLine($"[RUNTIME] Dispatch result: {result}"); + Log.Info($"DispatchEntry returned: {result}"); + Log.Info($"Dispatch result: {result}"); LastExecutionTrace = _cpuDispatcher.LastImportResolutionTrace; LastMilestoneLog = _cpuDispatcher.LastMilestoneLog; LastSessionSummary = BuildSessionSummary(_cpuDispatcher.LastSessionSummary); @@ -434,8 +437,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime moduleName = $"module#{i}"; } - Console.Error.WriteLine( - $"[RUNTIME] Starting module {moduleName}: dt_init=0x{initEntryPoint:X16}"); + Log.Info( + $"Starting module {moduleName}: dt_init=0x{initEntryPoint:X16}"); var result = _cpuDispatcher.DispatchModuleInitializer( initEntryPoint, @@ -446,8 +449,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime _cpuExecutionOptions); if (result != OrbisGen2Result.ORBIS_GEN2_OK) { - Console.Error.WriteLine( - $"[RUNTIME] Module start failed: {moduleName} -> {result}"); + Log.Error( + $"Module start failed: {moduleName} -> {result}"); return result; } } @@ -468,8 +471,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime return null; } - Console.Error.WriteLine( - $"[RUNTIME] Running initializers for {label}: preinit={image.PreInitializerFunctions.Count}, init={image.InitializerFunctions.Count}"); + Log.Info( + $"Running initializers for {label}: preinit={image.PreInitializerFunctions.Count}, init={image.InitializerFunctions.Count}"); var result = RunInitializerList( $"{label}:preinit", @@ -508,8 +511,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime continue; } - Console.Error.WriteLine( - $"[RUNTIME] Initializer {label}[{i}] -> 0x{initializerAddress:X16}"); + Log.Debug( + $" Initializer {label}[{i}] -> 0x{initializerAddress:X16}"); var result = _cpuDispatcher.DispatchEntry( initializerAddress, @@ -577,7 +580,7 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime .ToArray(); if (skippedModules.Length > 0) { - Console.Error.WriteLine($"[RUNTIME] Skipping {skippedModules.Length} core module(s): {string.Join(", ", skippedModules)}"); + Log.Info($"Skipping {skippedModules.Length} core module(s): {string.Join(", ", skippedModules)}"); } if (modulePaths.Length == 0) @@ -585,8 +588,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime return loadedImages; } - Console.Error.WriteLine($"[RUNTIME] Module search directories: {string.Join(", ", moduleDirectories)}"); - Console.Error.WriteLine($"[RUNTIME] Loading {modulePaths.Length} module(s)..."); + Log.Debug($"Module search directories: {string.Join(", ", moduleDirectories)}"); + Log.Info($"Loading {modulePaths.Length} module(s)..."); var loadedModules = 0; var failedModules = 0; var mergedImportCount = 0; @@ -621,18 +624,18 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime loadedImages.Add(new LoadedModuleImage(modulePath, moduleImage)); loadedModules++; - Console.Error.WriteLine( - $"[RUNTIME] Loaded module {Path.GetFileName(modulePath)}: entry=0x{moduleImage.EntryPoint:X16}, imports={moduleImage.ImportStubs.Count}, symbols={moduleImage.RuntimeSymbols.Count}"); + Log.Info( + $"Loaded module {Path.GetFileName(modulePath)}: entry=0x{moduleImage.EntryPoint:X16}, imports={moduleImage.ImportStubs.Count}, symbols={moduleImage.RuntimeSymbols.Count}"); } catch (Exception ex) { failedModules++; - Console.Error.WriteLine($"[RUNTIME] Module load failed: {modulePath} ({ex.GetType().Name}: {ex.Message})"); + Log.Error($"Module load failed: {modulePath} ({ex.GetType().Name}: {ex.Message})", ex); } } - Console.Error.WriteLine( - $"[RUNTIME] Module preload summary: loaded={loadedModules}, failed={failedModules}, merged_imports={mergedImportCount}, merged_symbols={mergedSymbolCount}"); + Log.Info( + $"Module preload summary: loaded={loadedModules}, failed={failedModules}, merged_imports={mergedImportCount}, merged_symbols={mergedSymbolCount}"); return loadedImages; } @@ -652,8 +655,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime if (rebound != 0 || unresolved != 0) { - Console.Error.WriteLine( - $"[RUNTIME] Imported data rebind: rebound={rebound}, unresolved={unresolved}"); + Log.Info( + $"Imported data rebind: rebound={rebound}, unresolved={unresolved}"); } } @@ -685,8 +688,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime { if (logRebind) { - Console.Error.WriteLine( - $"[RUNTIME] Imported data unresolved: nid={relocation.Nid} target=0x{relocation.TargetAddress:X16} addend=0x{unchecked((ulong)relocation.Addend):X16}"); + Log.Warning( + $"Imported data unresolved: nid={relocation.Nid} target=0x{relocation.TargetAddress:X16} addend=0x{unchecked((ulong)relocation.Addend):X16}"); } unresolved++; @@ -698,8 +701,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime { if (logRebind) { - Console.Error.WriteLine( - $"[RUNTIME] Imported data write-failed: nid={relocation.Nid} target=0x{relocation.TargetAddress:X16} value=0x{reboundValue:X16}"); + Log.Error( + $"Imported data write-failed: nid={relocation.Nid} target=0x{relocation.TargetAddress:X16} value=0x{reboundValue:X16}"); } unresolved++; @@ -708,8 +711,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime if (logRebind) { - Console.Error.WriteLine( - $"[RUNTIME] Imported data rebound: nid={relocation.Nid} target=0x{relocation.TargetAddress:X16} value=0x{reboundValue:X16}"); + Log.Debug( + $"Imported data rebound: nid={relocation.Nid} target=0x{relocation.TargetAddress:X16} value=0x{reboundValue:X16}"); } rebound++; @@ -745,8 +748,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime { if (!string.Equals(existingNid, nid, StringComparison.Ordinal)) { - Console.Error.WriteLine( - $"[RUNTIME] Import stub conflict at 0x{address:X16}: keep={existingNid}, skip={nid} ({Path.GetFileName(modulePath)})"); + Log.Warning( + $"Import stub conflict at 0x{address:X16}: keep={existingNid}, skip={nid} ({Path.GetFileName(modulePath)})"); } continue; @@ -855,8 +858,8 @@ public sealed class SharpEmuRuntime : ISharpEmuRuntime image.EntryPoint, isMain, isSystemModule); - Console.Error.WriteLine( - $"[RUNTIME] Registered module handle={handle} name={Path.GetFileName(modulePath)} base=0x{baseAddress:X16} size=0x{size:X16}"); + Log.Info( + $"Registered module handle={handle} name={Path.GetFileName(modulePath)} base=0x{baseAddress:X16} size=0x{size:X16}"); } private static bool TryComputeImageRange(SelfImage image, out ulong baseAddress, out ulong size)