From 1859b4ce268b49b0494e8e2a63d0a2deba969907 Mon Sep 17 00:00:00 2001 From: Alex Barney Date: Wed, 19 Jun 2019 15:48:13 -0500 Subject: [PATCH] Add FS access log --- src/LibHac/Fs/Accessors/DirectoryHandle.cs | 2 + src/LibHac/Fs/Accessors/FileHandle.cs | 2 + src/LibHac/Fs/Accessors/FileSystemAccessor.cs | 12 +- src/LibHac/Fs/Accessors/IAccessLogger.cs | 7 +- src/LibHac/Fs/FileSystemManager.cs | 297 ++++++++++++++++-- src/LibHac/Horizon.cs | 8 + src/hactoolnet/ConsoleAccessLog.cs | 15 + src/hactoolnet/TimeSpanTimer.cs | 16 + 8 files changed, 328 insertions(+), 31 deletions(-) create mode 100644 src/hactoolnet/ConsoleAccessLog.cs create mode 100644 src/hactoolnet/TimeSpanTimer.cs diff --git a/src/LibHac/Fs/Accessors/DirectoryHandle.cs b/src/LibHac/Fs/Accessors/DirectoryHandle.cs index 798ec4b6..044509ae 100644 --- a/src/LibHac/Fs/Accessors/DirectoryHandle.cs +++ b/src/LibHac/Fs/Accessors/DirectoryHandle.cs @@ -11,6 +11,8 @@ namespace LibHac.Fs.Accessors Directory = directory; } + public int GetId() => Directory.GetHashCode(); + public void Dispose() { Directory.Dispose(); diff --git a/src/LibHac/Fs/Accessors/FileHandle.cs b/src/LibHac/Fs/Accessors/FileHandle.cs index b4b94c70..be3042d2 100644 --- a/src/LibHac/Fs/Accessors/FileHandle.cs +++ b/src/LibHac/Fs/Accessors/FileHandle.cs @@ -11,6 +11,8 @@ namespace LibHac.Fs.Accessors File = file; } + public int GetId() => File.GetHashCode(); + public void Dispose() { File.Dispose(); diff --git a/src/LibHac/Fs/Accessors/FileSystemAccessor.cs b/src/LibHac/Fs/Accessors/FileSystemAccessor.cs index b0b65af3..ba0ab22a 100644 --- a/src/LibHac/Fs/Accessors/FileSystemAccessor.cs +++ b/src/LibHac/Fs/Accessors/FileSystemAccessor.cs @@ -11,28 +11,20 @@ namespace LibHac.Fs.Accessors public string Name { get; } private IFileSystem FileSystem { get; } - private IAccessLogger Logger { get; } - private ITimeSpanGenerator Timer { get; } private HashSet OpenFiles { get; } = new HashSet(); private HashSet OpenDirectories { get; } = new HashSet(); private readonly object _locker = new object(); + internal bool IsAccessLogEnabled { get; set; } + public FileSystemAccessor(string name, IFileSystem baseFileSystem) { Name = name; FileSystem = baseFileSystem; } - public FileSystemAccessor(string name, IFileSystem baseFileSystem, IAccessLogger logger, ITimeSpanGenerator timer) - { - Name = name; - FileSystem = baseFileSystem; - Logger = logger; - Timer = timer; - } - public void CreateDirectory(string path) { FileSystem.CreateDirectory(path); diff --git a/src/LibHac/Fs/Accessors/IAccessLogger.cs b/src/LibHac/Fs/Accessors/IAccessLogger.cs index a01db508..2968435c 100644 --- a/src/LibHac/Fs/Accessors/IAccessLogger.cs +++ b/src/LibHac/Fs/Accessors/IAccessLogger.cs @@ -1,7 +1,10 @@ -namespace LibHac.Fs.Accessors +using System; +using System.Runtime.CompilerServices; + +namespace LibHac.Fs.Accessors { public interface IAccessLogger { - + void Log(TimeSpan startTime, TimeSpan endTime, int handleId, string message, [CallerMemberName] string caller = ""); } } \ No newline at end of file diff --git a/src/LibHac/Fs/FileSystemManager.cs b/src/LibHac/Fs/FileSystemManager.cs index 710e3ab0..5a5287c6 100644 --- a/src/LibHac/Fs/FileSystemManager.cs +++ b/src/LibHac/Fs/FileSystemManager.cs @@ -1,5 +1,6 @@ using System; using System.Collections.Generic; +using System.Runtime.CompilerServices; using LibHac.Fs.Accessors; using static LibHac.Results; @@ -10,19 +11,32 @@ namespace LibHac.Fs public class FileSystemManager { internal Horizon Os { get; } + internal ITimeSpanGenerator Time { get; } + internal IAccessLogger Logger { get; } internal MountTable MountTable { get; } = new MountTable(); + private bool AccessLogEnabled { get; set; } = true; + public FileSystemManager(Horizon os) { Os = os; } + public FileSystemManager(Horizon os, IAccessLogger logger, ITimeSpanGenerator timer) + { + Os = os; + Logger = logger; + Time = timer; + } + public void Register(string mountName, IFileSystem fileSystem) { var accessor = new FileSystemAccessor(mountName, fileSystem); MountTable.Mount(accessor); + + accessor.IsAccessLogEnabled = IsEnabledAccessLog(); } public void CreateDirectory(string path) @@ -30,7 +44,18 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - fileSystem.CreateDirectory(subPath.ToString()); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + fileSystem.CreateDirectory(subPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{path}\""); + } + else + { + fileSystem.CreateDirectory(subPath.ToString()); + } } public void CreateFile(string path, long size) @@ -43,7 +68,18 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - fileSystem.CreateFile(subPath.ToString(), size, options); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + fileSystem.CreateFile(subPath.ToString(), size, options); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{path}\", size: {size}"); + } + else + { + fileSystem.CreateFile(subPath.ToString(), size, options); + } } public void DeleteDirectory(string path) @@ -51,7 +87,18 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - fileSystem.DeleteDirectory(subPath.ToString()); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + fileSystem.DeleteDirectory(subPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{path}\""); + } + else + { + fileSystem.DeleteDirectory(subPath.ToString()); + } } public void DeleteDirectoryRecursively(string path) @@ -59,7 +106,18 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - fileSystem.DeleteDirectoryRecursively(subPath.ToString()); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + fileSystem.DeleteDirectoryRecursively(subPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{path}\""); + } + else + { + fileSystem.DeleteDirectoryRecursively(subPath.ToString()); + } } public void CleanDirectoryRecursively(string path) @@ -67,7 +125,18 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - fileSystem.CleanDirectoryRecursively(subPath.ToString()); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + fileSystem.CleanDirectoryRecursively(subPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{path}\""); + } + else + { + fileSystem.CleanDirectoryRecursively(subPath.ToString()); + } } public void DeleteFile(string path) @@ -75,7 +144,18 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - fileSystem.DeleteFile(subPath.ToString()); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + fileSystem.DeleteFile(subPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{path}\""); + } + else + { + fileSystem.DeleteFile(subPath.ToString()); + } } public void RenameDirectory(string oldPath, string newPath) @@ -91,7 +171,18 @@ namespace LibHac.Fs ThrowHelper.ThrowResult(ResultFsDifferentDestFileSystem); } - oldFileSystem.RenameDirectory(oldSubPath.ToString(), newSubPath.ToString()); + if (IsEnabledAccessLog() && oldFileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + oldFileSystem.RenameDirectory(oldSubPath.ToString(), newSubPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{oldPath}\", new_path: \"{newPath}\""); + } + else + { + oldFileSystem.RenameDirectory(oldSubPath.ToString(), newSubPath.ToString()); + } } public void RenameFile(string oldPath, string newPath) @@ -107,7 +198,18 @@ namespace LibHac.Fs ThrowHelper.ThrowResult(ResultFsDifferentDestFileSystem); } - oldFileSystem.RenameFile(oldSubPath.ToString(), newSubPath.ToString()); + if (IsEnabledAccessLog() && oldFileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + oldFileSystem.RenameFile(oldSubPath.ToString(), newSubPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{oldPath}\", new_path: \"{newPath}\""); + } + else + { + oldFileSystem.RenameFile(oldSubPath.ToString(), newSubPath.ToString()); + } } public DirectoryEntryType GetEntryType(string path) @@ -115,7 +217,22 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - return fileSystem.GetEntryType(subPath.ToString()); + DirectoryEntryType type; + + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + type = fileSystem.GetEntryType(subPath.ToString()); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", path: \"{path}\""); + } + else + { + type = fileSystem.GetEntryType(subPath.ToString()); + } + + return type; } public FileHandle OpenFile(string path, OpenMode mode) @@ -123,9 +240,24 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - FileAccessor file = fileSystem.OpenFile(subPath.ToString(), mode); + FileHandle handle; - return new FileHandle(file); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + FileAccessor file = fileSystem.OpenFile(subPath.ToString(), mode); + handle = new FileHandle(file); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, handle, $", path: \"{path}\", open_mode: {mode}"); + } + else + { + FileAccessor file = fileSystem.OpenFile(subPath.ToString(), mode); + handle = new FileHandle(file); + } + + return handle; } public DirectoryHandle OpenDirectory(string path, OpenDirectoryMode mode) @@ -133,9 +265,24 @@ namespace LibHac.Fs FindFileSystem(path.AsSpan(), out FileSystemAccessor fileSystem, out ReadOnlySpan subPath) .ThrowIfFailure(); - DirectoryAccessor dir = fileSystem.OpenDirectory(subPath.ToString(), mode); + DirectoryHandle handle; - return new DirectoryHandle(dir); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + DirectoryAccessor dir = fileSystem.OpenDirectory(subPath.ToString(), mode); + handle = new DirectoryHandle(dir); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, handle, $", path: \"{path}\", open_mode: {mode}"); + } + else + { + DirectoryAccessor dir = fileSystem.OpenDirectory(subPath.ToString(), mode); + handle = new DirectoryHandle(dir); + } + + return handle; } public long GetFreeSpaceSize(string path) @@ -166,7 +313,18 @@ namespace LibHac.Fs { MountTable.Find(mountName, out FileSystemAccessor fileSystem).ThrowIfFailure(); - fileSystem.Commit(); + if (IsEnabledAccessLog() && fileSystem.IsAccessLogEnabled) + { + TimeSpan startTime = Time.GetCurrent(); + fileSystem.Commit(); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, $", name: \"{mountName}\""); + } + else + { + fileSystem.Commit(); + } } // ========================== @@ -179,7 +337,22 @@ namespace LibHac.Fs public int ReadFile(FileHandle handle, Span destination, long offset, ReadOption option) { - return handle.File.Read(destination, offset, option); + int bytesRead; + + if (IsEnabledAccessLog() && IsEnabledHandleAccessLog(handle)) + { + TimeSpan startTime = Time.GetCurrent(); + bytesRead = handle.File.Read(destination, offset, option); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, handle, $", offset: {offset}, size: {destination.Length}"); + } + else + { + bytesRead = handle.File.Read(destination, offset, option); + } + + return bytesRead; } public void WriteFile(FileHandle handle, ReadOnlySpan source, long offset) @@ -189,12 +362,36 @@ namespace LibHac.Fs public void WriteFile(FileHandle handle, ReadOnlySpan source, long offset, WriteOption option) { - handle.File.Write(source, offset, option); + if (IsEnabledAccessLog() && IsEnabledHandleAccessLog(handle)) + { + TimeSpan startTime = Time.GetCurrent(); + handle.File.Write(source, offset, option); + TimeSpan endTime = Time.GetCurrent(); + + string optionString = (option & WriteOption.Flush) == 0 ? "" : $", write_option: {option}"; + + OutputAccessLog(startTime, endTime, handle, $", offset: {offset}, size: {source.Length}{optionString}"); + } + else + { + handle.File.Write(source, offset, option); + } } public void FlushFile(FileHandle handle) { - handle.File.Flush(); + if (IsEnabledAccessLog() && IsEnabledHandleAccessLog(handle)) + { + TimeSpan startTime = Time.GetCurrent(); + handle.File.Flush(); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, handle, string.Empty); + } + else + { + handle.File.Flush(); + } } public long GetFileSize(FileHandle handle) @@ -204,7 +401,18 @@ namespace LibHac.Fs public void SetFileSize(FileHandle handle, long size) { - handle.File.SetSize(size); + if (IsEnabledAccessLog() && IsEnabledHandleAccessLog(handle)) + { + TimeSpan startTime = Time.GetCurrent(); + handle.File.SetSize(size); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, handle, $", size: {size}"); + } + else + { + handle.File.SetSize(size); + } } public OpenMode GetFileOpenMode(FileHandle handle) @@ -214,7 +422,18 @@ namespace LibHac.Fs public void CloseFile(FileHandle handle) { - handle.File.Dispose(); + if (IsEnabledAccessLog() && IsEnabledHandleAccessLog(handle)) + { + TimeSpan startTime = Time.GetCurrent(); + handle.Dispose(); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, handle, string.Empty); + } + else + { + handle.Dispose(); + } } // ========================== @@ -227,6 +446,16 @@ namespace LibHac.Fs public IEnumerable ReadDirectory(DirectoryHandle handle) { + if (IsEnabledAccessLog() && IsEnabledHandleAccessLog(handle)) + { + TimeSpan startTime = Time.GetCurrent(); + IEnumerable entries = handle.Directory.Read(); + TimeSpan endTime = Time.GetCurrent(); + + OutputAccessLog(startTime, endTime, handle, string.Empty); + return entries; + } + return handle.Directory.Read(); } @@ -278,5 +507,35 @@ namespace LibHac.Fs return ResultSuccess; } + + internal bool IsEnabledAccessLog() + { + return AccessLogEnabled && Logger != null && Time != null; + } + + internal bool IsEnabledHandleAccessLog(FileHandle handle) + { + return handle.File.Parent.IsAccessLogEnabled; + } + + internal bool IsEnabledHandleAccessLog(DirectoryHandle handle) + { + return handle.Directory.Parent.IsAccessLogEnabled; + } + + internal void OutputAccessLog(TimeSpan startTime, TimeSpan endTime, string message, [CallerMemberName] string caller = "") + { + Logger.Log(startTime, endTime, 0, message, caller); + } + + internal void OutputAccessLog(TimeSpan startTime, TimeSpan endTime, FileHandle handle, string message, [CallerMemberName] string caller = "") + { + Logger.Log(startTime, endTime, handle.GetId(), message, caller); + } + + internal void OutputAccessLog(TimeSpan startTime, TimeSpan endTime, DirectoryHandle handle, string message, [CallerMemberName] string caller = "") + { + Logger.Log(startTime, endTime, handle.GetId(), message, caller); + } } } diff --git a/src/LibHac/Horizon.cs b/src/LibHac/Horizon.cs index cfb0ccff..d0e81d7e 100644 --- a/src/LibHac/Horizon.cs +++ b/src/LibHac/Horizon.cs @@ -1,4 +1,5 @@ using LibHac.Fs; +using LibHac.Fs.Accessors; namespace LibHac { @@ -12,5 +13,12 @@ namespace LibHac { Fs = new FileSystemManager(this); } + + public Horizon(IAccessLogger logger, ITimeSpanGenerator timer) + { + Time = timer; + + Fs = new FileSystemManager(this, logger, timer); + } } } diff --git a/src/hactoolnet/ConsoleAccessLog.cs b/src/hactoolnet/ConsoleAccessLog.cs new file mode 100644 index 00000000..70813b1f --- /dev/null +++ b/src/hactoolnet/ConsoleAccessLog.cs @@ -0,0 +1,15 @@ +using System; +using System.Runtime.CompilerServices; +using LibHac.Fs.Accessors; + +namespace hactoolnet +{ + public class ConsoleAccessLog : IAccessLogger + { + public void Log(TimeSpan startTime, TimeSpan endTime, int handleId, string message, [CallerMemberName] string caller = "") + { + Console.WriteLine( + $"FS_ACCESS: {{ start: {startTime.Milliseconds,9}, end: {endTime.Milliseconds,9}, handle: 0x{handleId:x8}, function: \"{caller}\"{message} }}"); + } + } +} diff --git a/src/hactoolnet/TimeSpanTimer.cs b/src/hactoolnet/TimeSpanTimer.cs new file mode 100644 index 00000000..9235181d --- /dev/null +++ b/src/hactoolnet/TimeSpanTimer.cs @@ -0,0 +1,16 @@ +using System; +using System.Diagnostics; +using LibHac; + +namespace hactoolnet +{ + public class TimeSpanTimer : ITimeSpanGenerator + { + private Stopwatch Timer = Stopwatch.StartNew(); + + public TimeSpan GetCurrent() + { + return Timer.Elapsed; + } + } +}