diff --git a/MareSynchronos/Export/MareCharaFileManager.cs b/MareSynchronos/Export/MareCharaFileManager.cs index 72a7660..6f1b146 100644 --- a/MareSynchronos/Export/MareCharaFileManager.cs +++ b/MareSynchronos/Export/MareCharaFileManager.cs @@ -8,11 +8,15 @@ using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; using MareSynchronos.Models; using CharacterData = MareSynchronos.API.Data.CharacterData; +using Microsoft.Extensions.Logging; +using MareSynchronos.Factories; namespace MareSynchronos.Export; public class MareCharaFileManager { + private readonly ILogger _logger; private readonly MareMediator _mediator; + private readonly GameObjectHandlerFactory _gameObjectHandlerFactory; private readonly FileCacheManager _manager; private readonly IpcManager _ipcManager; private readonly MareConfigService _configService; @@ -22,10 +26,13 @@ public class MareCharaFileManager public bool CurrentlyWorking { get; private set; } = false; private static int GlobalFileCounter = 0; - public MareCharaFileManager(MareMediator mediator, FileCacheManager manager, IpcManager ipcManager, MareConfigService configService, DalamudUtil dalamudUtil) + public MareCharaFileManager(ILogger logger, MareMediator mediator, GameObjectHandlerFactory gameObjectHandlerFactory, + FileCacheManager manager, IpcManager ipcManager, MareConfigService configService, DalamudUtil dalamudUtil) { _factory = new(manager); + _logger = logger; _mediator = mediator; + _gameObjectHandlerFactory = gameObjectHandlerFactory; _manager = manager; _ipcManager = ipcManager; _configService = configService; @@ -58,20 +65,20 @@ public class MareCharaFileManager while ((length = reader2.Read(buffer)) > 0) { if (length < bufferSize) bufferSize = (int)length; - Logger.Verbose($"Reading chunk {chunk++} {bufferSize}/{length} of {filePath}"); + _logger.LogTrace($"Reading chunk {chunk++} {bufferSize}/{length} of {filePath}"); wr.Write(length > bufferSize ? buffer : buffer.Take((int)length).ToArray()); }*/ - Logger.Info("Read Mare Chara File"); - Logger.Info("Version: " + (LoadedCharaFile?.Version ?? -1)); + _logger.LogInformation("Read Mare Chara File"); + _logger.LogInformation("Version: " + (LoadedCharaFile?.Version ?? -1)); long expectedLength = 0; if (LoadedCharaFile != null) { - Logger.Verbose("Data"); + _logger.LogTrace("Data"); foreach (var item in LoadedCharaFile.CharaFileData.FileSwaps) { foreach (var gamePath in item.GamePaths) { - Logger.Verbose("Swap: " + gamePath + " => " + item.FileSwapPath); + _logger.LogTrace("Swap: " + gamePath + " => " + item.FileSwapPath); } } @@ -82,11 +89,11 @@ public class MareCharaFileManager expectedLength += item.Length; foreach (var gamePath in item.GamePaths) { - Logger.Verbose($"File {itemNr}: " + gamePath + " = " + item.Length); + _logger.LogTrace($"File {itemNr}: " + gamePath + " = " + item.Length); } } - Logger.Info("Expected length: " + expectedLength); + _logger.LogInformation("Expected length: " + expectedLength); } } @@ -108,7 +115,7 @@ public class MareCharaFileManager using var lz4Stream = new LZ4Stream(unwrapped, LZ4StreamMode.Decompress, LZ4StreamFlags.HighCompression); using var reader = new BinaryReader(lz4Stream); LoadedCharaFile.AdvanceReaderToData(reader); - Logger.Debug("Applying to " + charaTarget.Name.TextValue); + _logger.LogDebug("Applying to " + charaTarget.Name.TextValue); extractedFiles = ExtractFilesFromCharaFile(LoadedCharaFile, reader); Dictionary fileSwaps = new(StringComparer.Ordinal); foreach (var fileSwap in LoadedCharaFile.CharaFileData.FileSwaps) @@ -118,15 +125,16 @@ public class MareCharaFileManager fileSwaps.Add(path, fileSwap.FileSwapPath); } } + var applicationId = Guid.NewGuid(); _ipcManager.ToggleGposeQueueMode(on: true); - _ipcManager.PenumbraRemoveTemporaryCollection(charaTarget.Name.TextValue); - _ipcManager.PenumbraSetTemporaryMods(charaTarget.Name.TextValue, + _ipcManager.PenumbraRemoveTemporaryCollection(_logger, applicationId, charaTarget.Name.TextValue); + _ipcManager.PenumbraSetTemporaryMods(_logger, applicationId, charaTarget.Name.TextValue, extractedFiles.Union(fileSwaps).ToDictionary(d => d.Key, d => d.Value, StringComparer.Ordinal), LoadedCharaFile.CharaFileData.ManipulationData); - using GameObjectHandler tempHandler = new(_mediator, ObjectKind.Player, () => charaTarget.Address, false); - await _ipcManager.GlamourerApplyAll(LoadedCharaFile.CharaFileData.GlamourerData, tempHandler, disposeCts.Token).ConfigureAwait(false); + using GameObjectHandler tempHandler = _gameObjectHandlerFactory.Create(ObjectKind.Player, () => charaTarget.Address, false); + await _ipcManager.GlamourerApplyAll(_logger, tempHandler, LoadedCharaFile.CharaFileData.GlamourerData, applicationId, disposeCts.Token).ConfigureAwait(false); _dalamudUtil.WaitWhileGposeCharacterIsDrawing(charaTarget.Address, 30000); - _ipcManager.PenumbraRemoveTemporaryCollection(charaTarget.Name.TextValue); + _ipcManager.PenumbraRemoveTemporaryCollection(_logger, applicationId, charaTarget.Name.TextValue); _ipcManager.ToggleGposeQueueMode(on: false); } } @@ -135,7 +143,7 @@ public class MareCharaFileManager { CurrentlyWorking = false; - Logger.Debug("Clearing local files"); + _logger.LogDebug("Clearing local files"); foreach (var file in extractedFiles) { File.Delete(file.Value); @@ -158,7 +166,7 @@ public class MareCharaFileManager while (length > 0) { if (length < bufferSize) bufferSize = (int)length; - Logger.Verbose($"Reading chunk {chunk++} {bufferSize}/{length} of {fileName}"); + _logger.LogTrace($"Reading chunk {chunk++} {bufferSize}/{length} of {fileName}"); buffer = reader.ReadBytes(bufferSize); wr.Write(length > bufferSize ? buffer : buffer.Take((int)length).ToArray()); length -= bufferSize; @@ -167,7 +175,7 @@ public class MareCharaFileManager foreach (var path in fileData.GamePaths) { gamePathToFilePath[path] = fileName; - Logger.Verbose(path + " => " + fileName); + _logger.LogTrace(path + " => " + fileName); } } @@ -192,7 +200,7 @@ public class MareCharaFileManager byte[] buffer = new byte[bufferSize]; var playerReplacements = dto.FileReplacements[ObjectKind.Player]; - foreach(var item in output.CharaFileData.Files) + foreach (var item in output.CharaFileData.Files) { var itemFromData = playerReplacements.First(f => f.GamePaths.Any(p => item.GamePaths.Contains(p, StringComparer.OrdinalIgnoreCase))); var file = _manager.GetFileCacheByHash(itemFromData.Hash)!; diff --git a/MareSynchronos/Factories/CachedPlayerFactory.cs b/MareSynchronos/Factories/CachedPlayerFactory.cs index 314eff2..57d72d2 100644 --- a/MareSynchronos/Factories/CachedPlayerFactory.cs +++ b/MareSynchronos/Factories/CachedPlayerFactory.cs @@ -4,6 +4,7 @@ using MareSynchronos.Managers; using MareSynchronos.Mediator; using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Factories; @@ -12,18 +13,24 @@ public class CachedPlayerFactory private readonly IpcManager _ipcManager; private readonly DalamudUtil _dalamudUtil; private readonly FileCacheManager _fileCacheManager; + private readonly GameObjectHandlerFactory _gameObjectHandlerFactory; private readonly MareMediator _mediator; + private readonly ILoggerFactory _loggerFactory; - public CachedPlayerFactory(IpcManager ipcManager, DalamudUtil dalamudUtil, FileCacheManager fileCacheManager, MareMediator mediator) + public CachedPlayerFactory(IpcManager ipcManager, DalamudUtil dalamudUtil, FileCacheManager fileCacheManager, + GameObjectHandlerFactory gameObjectHandlerFactory, + MareMediator mediator, ILoggerFactory loggerFactory) { _ipcManager = ipcManager; _dalamudUtil = dalamudUtil; _fileCacheManager = fileCacheManager; + _gameObjectHandlerFactory = gameObjectHandlerFactory; _mediator = mediator; + _loggerFactory = loggerFactory; } public CachedPlayer Create(OnlineUserIdentDto dto, ApiController apiController) { - return new CachedPlayer(dto, _ipcManager, apiController, _dalamudUtil, _fileCacheManager, _mediator); + return new CachedPlayer(_loggerFactory.CreateLogger(), dto, _gameObjectHandlerFactory, _ipcManager, apiController, _dalamudUtil, _fileCacheManager, _mediator); } } diff --git a/MareSynchronos/Factories/CharacterDataFactory.cs b/MareSynchronos/Factories/CharacterDataFactory.cs index b6bacb6..e35e655 100644 --- a/MareSynchronos/Factories/CharacterDataFactory.cs +++ b/MareSynchronos/Factories/CharacterDataFactory.cs @@ -13,6 +13,7 @@ using Weapon = MareSynchronos.Interop.Weapon; using MareSynchronos.FileCache; using MareSynchronos.Mediator; using System.Collections.Concurrent; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Factories; @@ -24,9 +25,10 @@ public class CharacterDataFactory : MediatorSubscriberBase private readonly FileCacheManager _fileCacheManager; private ConcurrentQueue> _processingQueue = new(); - public CharacterDataFactory(DalamudUtil dalamudUtil, IpcManager ipcManager, TransientResourceManager transientResourceManager, FileCacheManager fileReplacementFactory, MareMediator mediator) : base(mediator) + public CharacterDataFactory(ILogger logger, DalamudUtil dalamudUtil, IpcManager ipcManager, + TransientResourceManager transientResourceManager, FileCacheManager fileReplacementFactory, MareMediator mediator) : base(logger, mediator) { - Logger.Verbose("Creating " + nameof(CharacterDataFactory)); + _logger.LogTrace("Creating " + nameof(CharacterDataFactory)); _dalamudUtil = dalamudUtil; _ipcManager = ipcManager; _transientResourceManager = transientResourceManager; @@ -63,17 +65,17 @@ public class CharacterDataFactory : MediatorSubscriberBase catch { pointerIsZero = true; - Logger.Debug("NullRef for " + playerRelatedObject.ObjectKind); + _logger.LogDebug("NullRef for " + playerRelatedObject.ObjectKind); } } catch (Exception ex) { - Logger.Warn("Could not create data for " + playerRelatedObject.ObjectKind, ex); + _logger.LogWarning("Could not create data for " + playerRelatedObject.ObjectKind, ex); } if (pointerIsZero) { - Logger.Verbose("Pointer was zero for " + playerRelatedObject.ObjectKind); + _logger.LogTrace("Pointer was zero for " + playerRelatedObject.ObjectKind); previousData.FileReplacements.Remove(playerRelatedObject.ObjectKind); previousData.GlamourerString.Remove(playerRelatedObject.ObjectKind); return previousData; @@ -90,12 +92,12 @@ public class CharacterDataFactory : MediatorSubscriberBase catch (OperationCanceledException) { _processingQueue.Clear(); - Logger.Debug("Cancelled creating Character data"); + _logger.LogDebug("Cancelled creating Character data"); throw; } catch (Exception e) { - Logger.Warn("Failed to create " + playerRelatedObject.ObjectKind + " data", e); + _logger.LogWarning("Failed to create " + playerRelatedObject.ObjectKind + " data", e); } previousData.FileReplacements = previousFileReplacements; @@ -108,7 +110,7 @@ public class CharacterDataFactory : MediatorSubscriberBase var objectKind = playerRelatedObject.ObjectKind; var charaPointer = playerRelatedObject.Address; - Logger.Debug("Building character data for " + objectKind); + _logger.LogDebug("Building character data for " + objectKind); if (!previousData.FileReplacements.ContainsKey(objectKind)) { @@ -120,11 +122,11 @@ public class CharacterDataFactory : MediatorSubscriberBase } // wait until chara is not drawing and present so nothing spontaneously explodes - _dalamudUtil.WaitWhileCharacterIsDrawing(playerRelatedObject, 30000, ct: token); + _dalamudUtil.WaitWhileCharacterIsDrawing(_logger, playerRelatedObject, Guid.NewGuid(), 30000, ct: token); var chara = _dalamudUtil.CreateGameObject(charaPointer)!; while (!DalamudUtil.IsObjectPresent(chara)) { - Logger.Verbose("Character is null but it shouldn't be, waiting"); + _logger.LogTrace("Character is null but it shouldn't be, waiting"); await Task.Delay(50).ConfigureAwait(false); } @@ -151,10 +153,10 @@ public class CharacterDataFactory : MediatorSubscriberBase new HashSet(resolvedPaths.Select(c => new FileReplacement(c.Value, c.Key, _fileCacheManager)), FileReplacementComparer.Instance) .Where(p => p.HasFileReplacement).ToHashSet(); - Logger.Debug("== Static Replacements =="); + _logger.LogDebug("== Static Replacements =="); foreach (var replacement in previousData.FileReplacements[objectKind].Where(i => i.HasFileReplacement).OrderBy(i => i.GamePaths.First(), StringComparer.OrdinalIgnoreCase)) { - Logger.Debug(replacement.ToString()); + _logger.LogDebug(replacement.ToString()); } // if it's pet then it's summoner, if it's summoner we actually want to keep all filereplacements alive at all times @@ -167,7 +169,7 @@ public class CharacterDataFactory : MediatorSubscriberBase } } - Logger.Debug("Handling transient update for " + objectKind); + _logger.LogDebug("Handling transient update for " + objectKind); // remove all potentially gathered paths from the transient resource manager that are resolved through static resolving _transientResourceManager.ClearTransientPaths(charaPointer, previousData.FileReplacements[objectKind].SelectMany(c => c.GamePaths).ToList()); @@ -176,10 +178,10 @@ public class CharacterDataFactory : MediatorSubscriberBase var transientPaths = ManageSemiTransientData(objectKind, charaPointer); var resolvedTransientPaths = GetFileReplacementsFromPaths(transientPaths, new HashSet(StringComparer.Ordinal)); - Logger.Debug("== Transient Replacements =="); + _logger.LogDebug("== Transient Replacements =="); foreach (var replacement in resolvedTransientPaths.Select(c => new FileReplacement(c.Value, c.Key, _fileCacheManager)).OrderBy(f => f.ResolvedPath, StringComparer.Ordinal)) { - Logger.Debug(replacement.ToString()); + _logger.LogDebug(replacement.ToString()); previousData.FileReplacements[objectKind].Add(replacement); } @@ -193,7 +195,7 @@ public class CharacterDataFactory : MediatorSubscriberBase } st.Stop(); - Logger.Info("Building character data for " + objectKind + " took " + st.ElapsedMilliseconds + "ms"); + _logger.LogInformation("Building character data for " + objectKind + " took " + st.ElapsedMilliseconds + "ms"); return previousData; } @@ -235,7 +237,7 @@ public class CharacterDataFactory : MediatorSubscriberBase foreach (var item in _transientResourceManager.GetTransientResources((IntPtr)weaponObject)) { - Logger.Verbose("Found transient weapon resource: " + item); + _logger.LogTrace("Found transient weapon resource: " + item); forwardResolve.Add(item); } @@ -247,7 +249,7 @@ public class CharacterDataFactory : MediatorSubscriberBase foreach (var item in _transientResourceManager.GetTransientResources((IntPtr)offHandWeapon)) { - Logger.Verbose("Found transient offhand weapon resource: " + item); + _logger.LogTrace("Found transient offhand weapon resource: " + item); forwardResolve.Add(item); } } @@ -260,7 +262,7 @@ public class CharacterDataFactory : MediatorSubscriberBase } catch { - Logger.Warn("Could not get Decal data"); + _logger.LogWarning("Could not get Decal data"); } try { @@ -268,7 +270,7 @@ public class CharacterDataFactory : MediatorSubscriberBase } catch { - Logger.Warn("Could not get Legacy Body Decal Data"); + _logger.LogWarning("Could not get Legacy Body Decal Data"); } } @@ -287,10 +289,10 @@ public class CharacterDataFactory : MediatorSubscriberBase } catch { - Logger.Warn("Could not get model data"); + _logger.LogWarning("Could not get model data"); return; } - Logger.Verbose("Checking File Replacement for Model " + mdlPath); + _logger.LogTrace("Checking File Replacement for Model " + mdlPath); reverseResolve.Add(mdlPath); @@ -313,11 +315,11 @@ public class CharacterDataFactory : MediatorSubscriberBase } catch { - Logger.Warn("Could not get material data"); + _logger.LogWarning("Could not get material data"); return; } - Logger.Verbose("Checking File Replacement for Material " + fileName); + _logger.LogTrace("Checking File Replacement for Material " + fileName); var mtrlPath = fileName.Split("|")[2]; reverseResolve.Add(mtrlPath); @@ -332,12 +334,12 @@ public class CharacterDataFactory : MediatorSubscriberBase } catch { - Logger.Warn("Could not get Texture data for Material " + fileName); + _logger.LogWarning("Could not get Texture data for Material " + fileName); } if (string.IsNullOrEmpty(texPath)) continue; - Logger.Verbose("Checking File Replacement for Texture " + texPath); + _logger.LogTrace("Checking File Replacement for Texture " + texPath); AddReplacementsFromTexture(texPath, forwardResolve, reverseResolve); } @@ -345,12 +347,12 @@ public class CharacterDataFactory : MediatorSubscriberBase try { var shpkPath = "shader/sm5/shpk/" + new ByteString(mtrlResourceHandle->ShpkString).ToString(); - Logger.Verbose("Checking File Replacement for Shader " + shpkPath); + _logger.LogTrace("Checking File Replacement for Shader " + shpkPath); forwardResolve.Add(shpkPath); } catch { - Logger.Verbose("Could not find shpk for Material " + fileName); + _logger.LogTrace("Could not find shpk for Material " + fileName); } } @@ -358,7 +360,7 @@ public class CharacterDataFactory : MediatorSubscriberBase { if (string.IsNullOrEmpty(texPath)) return; - Logger.Verbose("Checking file Replacement for texture " + texPath); + _logger.LogTrace("Checking file Replacement for texture " + texPath); if (doNotReverseResolve) forwardResolve.Add(texPath); diff --git a/MareSynchronos/Factories/GameObjectHandlerFactory.cs b/MareSynchronos/Factories/GameObjectHandlerFactory.cs new file mode 100644 index 0000000..e165652 --- /dev/null +++ b/MareSynchronos/Factories/GameObjectHandlerFactory.cs @@ -0,0 +1,23 @@ +using MareSynchronos.API.Data.Enum; +using MareSynchronos.Mediator; +using MareSynchronos.Models; +using Microsoft.Extensions.Logging; + +namespace MareSynchronos.Factories; + +public class GameObjectHandlerFactory +{ + private readonly ILoggerFactory _loggerFactory; + private readonly MareMediator _mediator; + + public GameObjectHandlerFactory(ILoggerFactory loggerFactory, MareMediator mediator) + { + _loggerFactory = loggerFactory; + _mediator = mediator; + } + + public GameObjectHandler Create(ObjectKind objectKind, Func getAddress, bool isWatched) + { + return new GameObjectHandler(_loggerFactory.CreateLogger(), _mediator, objectKind, getAddress, isWatched); + } +} \ No newline at end of file diff --git a/MareSynchronos/Factories/PairFactory.cs b/MareSynchronos/Factories/PairFactory.cs index 8e8e228..ab565a8 100644 --- a/MareSynchronos/Factories/PairFactory.cs +++ b/MareSynchronos/Factories/PairFactory.cs @@ -1,6 +1,7 @@ using MareSynchronos.Managers; using MareSynchronos.MareConfiguration; using MareSynchronos.Models; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Factories; @@ -8,15 +9,17 @@ public class PairFactory { private readonly MareConfigService _configService; private readonly ServerConfigurationManager _serverConfigurationManager; + private readonly ILoggerFactory _loggerFactory; - public PairFactory(MareConfigService configService, ServerConfigurationManager serverConfigurationManager) + public PairFactory(MareConfigService configService, ServerConfigurationManager serverConfigurationManager, ILoggerFactory loggerFactory) { _configService = configService; _serverConfigurationManager = serverConfigurationManager; + _loggerFactory = loggerFactory; } public Pair Create() { - return new Pair(_configService, _serverConfigurationManager); + return new Pair(_loggerFactory.CreateLogger(), _configService, _serverConfigurationManager); } } diff --git a/MareSynchronos/FileCache/FileCacheManager.cs b/MareSynchronos/FileCache/FileCacheManager.cs index 8b79373..70a12f2 100644 --- a/MareSynchronos/FileCache/FileCacheManager.cs +++ b/MareSynchronos/FileCache/FileCacheManager.cs @@ -1,6 +1,7 @@ using MareSynchronos.Managers; using MareSynchronos.MareConfiguration; using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; using System.Collections.Concurrent; using System.Globalization; using System.Text; @@ -11,6 +12,7 @@ public class FileCacheManager : IDisposable { private const string _penumbraPrefix = "{penumbra}"; private const string _cachePrefix = "{cache}"; + private readonly ILogger _logger; private readonly IpcManager _ipcManager; private readonly MareConfigService _configService; private readonly string _csvPath; @@ -19,8 +21,9 @@ public class FileCacheManager : IDisposable public const string CsvSplit = "|"; private readonly object _fileWriteLock = new(); - public FileCacheManager(IpcManager ipcManager, MareConfigService configService) + public FileCacheManager(ILogger logger, IpcManager ipcManager, MareConfigService configService) { + _logger = logger; _ipcManager = ipcManager; _configService = configService; _csvPath = Path.Combine(configService.ConfigurationDirectory, "FileCache.csv"); @@ -48,7 +51,7 @@ public class FileCacheManager : IDisposable } catch (Exception) { - Logger.Warn($"Failed to initialize entry {entry}, ignoring"); + _logger.LogWarning($"Failed to initialize entry {entry}, ignoring"); } } } @@ -116,7 +119,7 @@ public class FileCacheManager : IDisposable if (entry == null) { - Logger.Debug("Found no entries for " + cleanedPath); + _logger.LogDebug("Found no entries for " + cleanedPath); return CreateFileEntry(path); } @@ -127,7 +130,7 @@ public class FileCacheManager : IDisposable public FileCacheEntity? CreateCacheEntry(string path) { - Logger.Verbose("Creating cache entry for " + path); + _logger.LogTrace("Creating cache entry for " + path); FileInfo fi = new(path); if (!fi.Exists) return null; var fullName = fi.FullName.ToLowerInvariant(); @@ -138,7 +141,7 @@ public class FileCacheManager : IDisposable public FileCacheEntity? CreateFileEntry(string path) { - Logger.Verbose("Creating file entry for " + path); + _logger.LogTrace("Creating file entry for " + path); FileInfo fi = new(path); if (!fi.Exists) return null; var fullName = fi.FullName.ToLowerInvariant(); @@ -158,7 +161,7 @@ public class FileCacheManager : IDisposable File.AppendAllLines(_csvPath, new[] { entity.CsvEntry }); } var result = GetFileCacheByPath(fileInfo.FullName); - Logger.Debug("Creating file cache for " + fileInfo.FullName + " success: " + (result != null)); + _logger.LogDebug("Creating file cache for " + fileInfo.FullName + " success: " + (result != null)); return result; } @@ -188,13 +191,13 @@ public class FileCacheManager : IDisposable public void RemoveHash(FileCacheEntity entity) { - Logger.Verbose("Removing " + entity.ResolvedFilepath); + _logger.LogTrace("Removing " + entity.ResolvedFilepath); _fileCaches.Remove(entity.PrefixedFilePath, out _); } public void UpdateHash(FileCacheEntity fileCache) { - Logger.Verbose("Updating hash for " + fileCache.ResolvedFilepath); + _logger.LogTrace("Updating hash for " + fileCache.ResolvedFilepath); fileCache.Hash = Crypto.GetFileHash(fileCache.ResolvedFilepath); fileCache.LastModifiedDateTicks = new FileInfo(fileCache.ResolvedFilepath).LastWriteTimeUtc.Ticks.ToString(CultureInfo.InvariantCulture); _fileCaches.Remove(fileCache.PrefixedFilePath, out _); @@ -222,7 +225,7 @@ public class FileCacheManager : IDisposable public void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + _logger.LogTrace($"Disposing {GetType()}"); WriteOutFullCsv(); } } diff --git a/MareSynchronos/FileCache/PeriodicFileScanner.cs b/MareSynchronos/FileCache/PeriodicFileScanner.cs index 98f80da..ce760f0 100644 --- a/MareSynchronos/FileCache/PeriodicFileScanner.cs +++ b/MareSynchronos/FileCache/PeriodicFileScanner.cs @@ -2,7 +2,7 @@ using MareSynchronos.Managers; using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; -using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.FileCache; @@ -15,10 +15,10 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable private Task? _fileScannerTask = null; public ConcurrentDictionary haltScanLocks = new(StringComparer.Ordinal); - public PeriodicFileScanner(IpcManager ipcManager, MareConfigService configService, FileCacheManager fileDbManager, MareMediator mediator) : base(mediator) + public PeriodicFileScanner(ILogger logger, IpcManager ipcManager, MareConfigService configService, + FileCacheManager fileDbManager, MareMediator mediator) : base(logger, mediator) { - Logger.Verbose("Creating " + nameof(PeriodicFileScanner)); - + _logger.LogTrace("Creating " + nameof(PeriodicFileScanner)); _ipcManager = ipcManager; _configService = configService; _fileDbManager = fileDbManager; @@ -156,19 +156,19 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable if (string.IsNullOrEmpty(penumbraDir) || !Directory.Exists(penumbraDir)) { penDirExists = false; - Logger.Warn("Penumbra directory is not set or does not exist."); + _logger.LogWarning("Penumbra directory is not set or does not exist."); } if (string.IsNullOrEmpty(_configService.Current.CacheFolder) || !Directory.Exists(_configService.Current.CacheFolder)) { cacheDirExists = false; - Logger.Warn("Mare Cache directory is not set or does not exist."); + _logger.LogWarning("Mare Cache directory is not set or does not exist."); } if (!penDirExists || !cacheDirExists) { return; } - Logger.Debug("Getting files from " + penumbraDir + " and " + _configService.Current.CacheFolder); + _logger.LogDebug("Getting files from " + penumbraDir + " and " + _configService.Current.CacheFolder); string[] ext = { ".mdl", ".tex", ".mtrl", ".tmb", ".pap", ".avfx", ".atex", ".sklb", ".eid", ".phyb", ".scd", ".skp", ".shpk" }; var scannedFiles = new ConcurrentDictionary(Directory.EnumerateFiles(penumbraDir!, "*.*", SearchOption.AllDirectories) @@ -204,20 +204,20 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable scannedFiles[validatedCacheResult.Item2.ResolvedFilepath] = true; if (validatedCacheResult.Item1 == FileState.RequireUpdate) { - Logger.Verbose("To update: " + validatedCacheResult.Item2.ResolvedFilepath); + _logger.LogTrace("To update: " + validatedCacheResult.Item2.ResolvedFilepath); entitiesToUpdate.Add(validatedCacheResult.Item2); } else if (validatedCacheResult.Item1 == FileState.RequireDeletion) { - Logger.Verbose("To delete: " + validatedCacheResult.Item2.ResolvedFilepath); + _logger.LogTrace("To delete: " + validatedCacheResult.Item2.ResolvedFilepath); entitiesToRemove.Add(validatedCacheResult.Item2); } } catch (Exception ex) { - Logger.Warn("Failed validating " + cache.ResolvedFilepath); - Logger.Warn(ex.Message); - Logger.Warn(ex.StackTrace); + _logger.LogWarning("Failed validating " + cache.ResolvedFilepath); + _logger.LogWarning(ex.Message); + _logger.LogWarning(ex.StackTrace); } Interlocked.Increment(ref _currentFileProgress); @@ -226,7 +226,7 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable if (!_ipcManager.CheckPenumbraApi()) { - Logger.Warn("Penumbra not available"); + _logger.LogWarning("Penumbra not available"); return; } @@ -239,14 +239,14 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable } catch (Exception ex) { - Logger.Warn("Error during enumerating FileCaches: " + ex.Message); + _logger.LogWarning("Error during enumerating FileCaches: " + ex.Message); } Task.WaitAll(dbTasks); if (!_ipcManager.CheckPenumbraApi()) { - Logger.Warn("Penumbra not available"); + _logger.LogWarning("Penumbra not available"); return; } @@ -265,11 +265,11 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable _fileDbManager.WriteOutFullCsv(); } - Logger.Verbose("Scanner validated existing db files"); + _logger.LogTrace("Scanner validated existing db files"); if (!_ipcManager.CheckPenumbraApi()) { - Logger.Warn("Penumbra not available"); + _logger.LogWarning("Penumbra not available"); return; } @@ -288,9 +288,9 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable } catch (Exception ex) { - Logger.Warn("Failed adding " + c.Key); - Logger.Warn(ex.Message); - Logger.Warn(ex.StackTrace); + _logger.LogWarning("Failed adding " + c.Key); + _logger.LogWarning(ex.Message); + _logger.LogWarning(ex.StackTrace); } Interlocked.Increment(ref _currentFileProgress); @@ -299,7 +299,7 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable if (!_ipcManager.CheckPenumbraApi()) { - Logger.Warn("Penumbra not available"); + _logger.LogWarning("Penumbra not available"); return; } @@ -308,9 +308,9 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable Task.WaitAll(dbTasks); - Logger.Verbose("Scanner added new files to db"); + _logger.LogTrace("Scanner added new files to db"); - Logger.Debug("Scan complete"); + _logger.LogDebug("Scan complete"); TotalFiles = 0; _currentFileProgress = 0; entitiesToRemove.Clear(); @@ -327,7 +327,7 @@ public class PeriodicFileScanner : MediatorSubscriberBase, IDisposable public void StartScan() { if (!_ipcManager.Initialized || !_configService.Current.HasValidSetup()) return; - Logger.Verbose("Penumbra is active, configuration is valid, scan"); + _logger.LogTrace("Penumbra is active, configuration is valid, scan"); InvokeScan(forced: true); } } diff --git a/MareSynchronos/Managers/CacheCreationService.cs b/MareSynchronos/Managers/CacheCreationService.cs index 4f9df7e..7edb0dc 100644 --- a/MareSynchronos/Managers/CacheCreationService.cs +++ b/MareSynchronos/Managers/CacheCreationService.cs @@ -4,6 +4,7 @@ using MareSynchronos.Factories; using MareSynchronos.Mediator; using MareSynchronos.Models; using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Managers; @@ -17,7 +18,8 @@ public class CacheCreationService : MediatorSubscriberBase, IDisposable private readonly List _playerRelatedObjects = new(); private CancellationTokenSource _palettePlusCts = new(); - public unsafe CacheCreationService(MareMediator mediator, CharacterDataFactory characterDataFactory, DalamudUtil dalamudUtil) : base(mediator) + public unsafe CacheCreationService(ILogger logger, MareMediator mediator, GameObjectHandlerFactory gameObjectHandlerFactory, + CharacterDataFactory characterDataFactory, DalamudUtil dalamudUtil) : base(logger, mediator) { _characterDataFactory = characterDataFactory; @@ -26,6 +28,15 @@ public class CacheCreationService : MediatorSubscriberBase, IDisposable var actualMsg = (CreateCacheForObjectMessage)msg; _cachesToCreate[actualMsg.ObjectToCreateFor.ObjectKind] = actualMsg.ObjectToCreateFor; }); + + _playerRelatedObjects.AddRange(new List() + { + gameObjectHandlerFactory.Create(ObjectKind.Player, () => dalamudUtil.PlayerPointer, true), + gameObjectHandlerFactory.Create(ObjectKind.MinionOrMount, () => (IntPtr)((Character*)dalamudUtil.PlayerPointer)->CompanionObject, true), + gameObjectHandlerFactory.Create(ObjectKind.Pet, () => dalamudUtil.GetPet(), true), + gameObjectHandlerFactory.Create(ObjectKind.Companion, () => dalamudUtil.GetCompanion(), true), + }); + Mediator.Subscribe(this, (msg) => { Task.Run(() => @@ -42,14 +53,6 @@ public class CacheCreationService : MediatorSubscriberBase, IDisposable Mediator.Subscribe(this, (msg) => HeelsOffsetChanged((HeelsOffsetMessage)msg)); Mediator.Subscribe(this, (msg) => PalettePlusChanged((PalettePlusMessage)msg)); Mediator.Subscribe(this, (msg) => _cachesToCreate[ObjectKind.Player] = _playerRelatedObjects.First(p => p.ObjectKind == ObjectKind.Player)); - - _playerRelatedObjects.AddRange(new List() - { - new(Mediator, ObjectKind.Player, () => dalamudUtil.PlayerPointer), - new(Mediator, ObjectKind.MinionOrMount, () => (IntPtr)((Character*)dalamudUtil.PlayerPointer)->CompanionObject), - new(Mediator, ObjectKind.Pet, () => dalamudUtil.GetPet()), - new(Mediator, ObjectKind.Companion, () => dalamudUtil.GetCompanion()), - }); } private void PalettePlusChanged(PalettePlusMessage msg) @@ -112,18 +115,18 @@ public class CacheCreationService : MediatorSubscriberBase, IDisposable } catch (Exception ex) { - Logger.Error("Error during Cache Creation Processing", ex); + _logger.LogCritical("Error during Cache Creation Processing", ex); } finally { - Logger.Debug("Cache Creation complete"); + _logger.LogDebug("Cache Creation complete"); } }, _cts.Token); } else if (_cachesToCreate.Any()) { - Logger.Debug("Cache Creation stored until previous creation finished"); + _logger.LogDebug("Cache Creation stored until previous creation finished"); } } diff --git a/MareSynchronos/Managers/CachedPlayer.cs b/MareSynchronos/Managers/CachedPlayer.cs index 8727bb6..44cf00d 100644 --- a/MareSynchronos/Managers/CachedPlayer.cs +++ b/MareSynchronos/Managers/CachedPlayer.cs @@ -1,14 +1,15 @@ using Dalamud.Interface.Internal.Notifications; using Dalamud.Logging; -using FFXIVClientStructs.FFXIV.Client.Game.Character; using MareSynchronos.API.Data; using MareSynchronos.API.Data.Enum; using MareSynchronos.API.Dto.User; +using MareSynchronos.Factories; using MareSynchronos.FileCache; using MareSynchronos.Mediator; using MareSynchronos.Models; using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Managers; @@ -16,6 +17,7 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable { private readonly ApiController _apiController; private readonly DalamudUtil _dalamudUtil; + private readonly GameObjectHandlerFactory _gameObjectHandlerFactory; private readonly IpcManager _ipcManager; private readonly FileCacheManager _fileDbManager; private API.Data.CharacterData _cachedData = new(); @@ -24,9 +26,12 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable private string _lastGlamourerData = string.Empty; private string _originalGlamourerData = string.Empty; - public CachedPlayer(OnlineUserIdentDto onlineUser, IpcManager ipcManager, ApiController apiController, DalamudUtil dalamudUtil, FileCacheManager fileDbManager, MareMediator mediator) : base(mediator) + public CachedPlayer(ILogger logger, OnlineUserIdentDto onlineUser, GameObjectHandlerFactory gameObjectHandlerFactory, + IpcManager ipcManager, ApiController apiController, + DalamudUtil dalamudUtil, FileCacheManager fileDbManager, MareMediator mediator) : base(logger, mediator) { OnlineUser = onlineUser; + _gameObjectHandlerFactory = gameObjectHandlerFactory; _ipcManager = ipcManager; _apiController = apiController; _dalamudUtil = dalamudUtil; @@ -40,41 +45,34 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable public void ApplyCharacterData(API.Data.CharacterData characterData, OptionalPluginWarning warning, bool forced = false) { - Logger.Debug("Received data for " + this); + _logger.LogDebug("Received data for " + this); - Logger.Debug("Checking for files to download for player " + PlayerName); - Logger.Debug("Hash for data is " + characterData.DataHash.Value + ", current cache hash is " + _cachedData.DataHash.Value); + _logger.LogDebug("Checking for files to download for player " + PlayerName); + _logger.LogDebug("Hash for data is " + characterData.DataHash.Value + ", current cache hash is " + _cachedData.DataHash.Value); - if (!_ipcManager.CheckPenumbraApi()) - { - return; - } - - if (!_ipcManager.CheckGlamourerApi()) - { - return; - } + if (!_ipcManager.CheckPenumbraApi()) return; + if (!_ipcManager.CheckGlamourerApi()) return; if (string.Equals(characterData.DataHash.Value, _cachedData.DataHash.Value, StringComparison.Ordinal) && !forced) return; - CheckUpdatedData(characterData, out bool updateModdedPaths, out List charaDataToUpdate); + CheckUpdatedData(_cachedData, characterData, forced, out var charaDataToUpdate); NotifyForMissingPlugins(characterData, warning); - _cachedData = characterData; + DownloadAndApplyCharacter(characterData, charaDataToUpdate); - DownloadAndApplyCharacter(characterData, charaDataToUpdate, updateModdedPaths); + _cachedData = characterData; } - private void CheckUpdatedData(API.Data.CharacterData newData, out bool updateModdedPaths, out List charaDataToUpdate) + private void CheckUpdatedData(API.Data.CharacterData oldData, API.Data.CharacterData newData, bool forced, out Dictionary> charaDataToUpdate) { - updateModdedPaths = false; charaDataToUpdate = new(); foreach (var objectKind in Enum.GetValues()) { - _cachedData.FileReplacements.TryGetValue(objectKind, out var existingFileReplacements); + charaDataToUpdate[objectKind] = new(); + oldData.FileReplacements.TryGetValue(objectKind, out var existingFileReplacements); newData.FileReplacements.TryGetValue(objectKind, out var newFileReplacements); - _cachedData.GlamourerData.TryGetValue(objectKind, out var existingGlamourerData); + oldData.GlamourerData.TryGetValue(objectKind, out var existingGlamourerData); newData.GlamourerData.TryGetValue(objectKind, out var newGlamourerData); bool hasNewButNotOldFileReplacements = newFileReplacements != null && existingFileReplacements == null; @@ -88,70 +86,75 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable if (hasNewButNotOldFileReplacements || hasOldButNotNewFileReplacements || hasNewButNotOldGlamourerData || hasOldButNotNewGlamourerData) { - Logger.Debug($"Updating {objectKind} (Some new data arrived: {hasNewButNotOldFileReplacements} {hasOldButNotNewFileReplacements} {hasNewButNotOldGlamourerData} {hasOldButNotNewGlamourerData})"); - updateModdedPaths = true; - charaDataToUpdate.Add(objectKind); - continue; + _logger.LogDebug($"Updating {objectKind} (Some new data arrived: {hasNewButNotOldFileReplacements} {hasOldButNotNewFileReplacements} {hasNewButNotOldGlamourerData} {hasOldButNotNewGlamourerData})"); + charaDataToUpdate[objectKind].Add(PlayerChanges.Mods); } if (hasNewAndOldFileReplacements) { - bool listsAreEqual = Enumerable.SequenceEqual(_cachedData.FileReplacements[objectKind], newData.FileReplacements[objectKind], FileReplacementDataComparer.Instance); - if (!listsAreEqual) + bool listsAreEqual = Enumerable.SequenceEqual(oldData.FileReplacements[objectKind], newData.FileReplacements[objectKind], FileReplacementDataComparer.Instance); + if (!listsAreEqual || forced) { - Logger.Debug($"Updating {objectKind} (FileReplacements not equal)"); - updateModdedPaths = true; - charaDataToUpdate.Add(objectKind); - continue; + _logger.LogDebug($"Updating {objectKind} (FileReplacements not equal)"); + charaDataToUpdate[objectKind].Add(PlayerChanges.Mods); } } if (hasNewAndOldGlamourerData) { - bool glamourerDataDifferent = !string.Equals(_cachedData.GlamourerData[objectKind], newData.GlamourerData[objectKind], StringComparison.Ordinal); - if (glamourerDataDifferent) + bool glamourerDataDifferent = !string.Equals(oldData.GlamourerData[objectKind], newData.GlamourerData[objectKind], StringComparison.Ordinal); + if (forced || glamourerDataDifferent) { - Logger.Debug($"Updating {objectKind} (Diff glamourer data)"); - charaDataToUpdate.Add(objectKind); - continue; + _logger.LogDebug($"Updating {objectKind} (Diff glamourer data)"); + charaDataToUpdate[objectKind].Add(PlayerChanges.Mods); } } if (objectKind == ObjectKind.Player) { - bool manipDataDifferent = !string.Equals(_cachedData.ManipulationData, newData.ManipulationData, StringComparison.Ordinal); - if (manipDataDifferent) + bool manipDataDifferent = !string.Equals(oldData.ManipulationData, newData.ManipulationData, StringComparison.Ordinal); + if (manipDataDifferent || forced) { - Logger.Debug($"Updating {objectKind} (Diff manip data)"); - charaDataToUpdate.Add(objectKind); - continue; + _logger.LogDebug($"Updating {objectKind} (Diff manip data)"); + charaDataToUpdate[objectKind].Add(PlayerChanges.Mods); } - bool heelsOffsetDifferent = _cachedData.HeelsOffset != newData.HeelsOffset; - if (heelsOffsetDifferent) + bool heelsOffsetDifferent = oldData.HeelsOffset != newData.HeelsOffset; + if (heelsOffsetDifferent || forced) { - Logger.Debug($"Updating {objectKind} (Diff heels data)"); - charaDataToUpdate.Add(objectKind); - continue; + _logger.LogDebug($"Updating {objectKind} (Diff heels data)"); + charaDataToUpdate[objectKind].Add(PlayerChanges.Heels); } - bool customizeDataDifferent = !string.Equals(_cachedData.CustomizePlusData, newData.CustomizePlusData, StringComparison.Ordinal); - if (customizeDataDifferent) + bool customizeDataDifferent = !string.Equals(oldData.CustomizePlusData, newData.CustomizePlusData, StringComparison.Ordinal); + if (customizeDataDifferent || forced) { - Logger.Debug($"Updating {objectKind} (Diff customize data)"); - charaDataToUpdate.Add(objectKind); - continue; + _logger.LogDebug($"Updating {objectKind} (Diff customize data)"); + charaDataToUpdate[objectKind].Add(PlayerChanges.Customize); } - bool palettePlusDataDifferent = !string.Equals(_cachedData.PalettePlusData, newData.PalettePlusData, StringComparison.Ordinal); - if (palettePlusDataDifferent) + bool palettePlusDataDifferent = !string.Equals(oldData.PalettePlusData, newData.PalettePlusData, StringComparison.Ordinal); + if (palettePlusDataDifferent || forced) { - Logger.Debug($"Updating {objectKind} (Diff palette data)"); - charaDataToUpdate.Add(objectKind); - continue; + _logger.LogDebug($"Updating {objectKind} (Diff palette data)"); + charaDataToUpdate[objectKind].Add(PlayerChanges.Palette); } } } + + foreach (var data in charaDataToUpdate.ToList()) + { + if (!data.Value.Any()) charaDataToUpdate.Remove(data.Key); + else charaDataToUpdate[data.Key] = data.Value.OrderBy(p => (int)p).ToHashSet(); + } + } + + private enum PlayerChanges + { + Heels = 1, + Customize = 2, + Palette = 3, + Mods = 4 } private void NotifyForMissingPlugins(API.Data.CharacterData characterData, OptionalPluginWarning warning) @@ -208,13 +211,15 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable if (string.IsNullOrEmpty(PlayerName)) return; // already disposed base.Dispose(); - - Logger.Debug("Disposing " + PlayerName + " (" + OnlineUser + ")"); + var name = PlayerName; + PlayerName = null; + _logger.LogDebug("Disposing " + name + " (" + OnlineUser + ")"); try { - Logger.Verbose($"Restoring state for {PlayerName} ({OnlineUser})"); + Guid applicationId = Guid.NewGuid(); + _logger.LogTrace($"[{applicationId}] Restoring state for {name} ({OnlineUser})"); _currentOtherChara?.Dispose(); - _ipcManager.PenumbraRemoveTemporaryCollection(PlayerName); + _ipcManager.PenumbraRemoveTemporaryCollection(_logger, applicationId, name); _downloadCancellationTokenSource?.Cancel(); _downloadCancellationTokenSource?.Dispose(); _downloadCancellationTokenSource = null; @@ -222,19 +227,19 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable { foreach (var item in _cachedData.FileReplacements) { - await RevertCustomizationData(item.Key).ConfigureAwait(false); + await RevertCustomizationData(item.Key, name, applicationId).ConfigureAwait(false); } } _currentOtherChara = null; } catch (Exception ex) { - Logger.Warn(ex.Message + Environment.NewLine + ex.StackTrace); + _logger.LogWarning(ex.Message + Environment.NewLine + ex.StackTrace); } finally { _cachedData = new(); - Logger.Debug("Disposing " + PlayerName + " complete"); + _logger.LogDebug("Disposing " + name + " complete"); PlayerName = null; } } @@ -242,7 +247,7 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable public void Initialize(string name) { PlayerName = name; - _currentOtherChara = new GameObjectHandler(Mediator, ObjectKind.Player, () => _dalamudUtil.GetPlayerCharacterFromObjectTableByName(PlayerName)?.Address ?? IntPtr.Zero, watchedObject: false); + _currentOtherChara = _gameObjectHandlerFactory.Create(ObjectKind.Player, () => _dalamudUtil.GetPlayerCharacterFromObjectTableByName(PlayerName)?.Address ?? IntPtr.Zero, false); _originalGlamourerData = _ipcManager.GlamourerGetCharacterCustomization(PlayerCharacter); _lastGlamourerData = _originalGlamourerData; @@ -256,7 +261,7 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable } }); - Logger.Debug("Initializing Player " + this); + _logger.LogDebug("Initializing Player " + this); } public override string ToString() @@ -264,126 +269,70 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable return OnlineUser.User.AliasOrUID + ":" + PlayerName + ":HasChar " + (PlayerCharacter != IntPtr.Zero); } - private void ApplyBaseData(Dictionary moddedPaths) + private void ApplyBaseData(Guid applicationId, Dictionary moddedPaths, string manipulationData) { - _ipcManager.PenumbraRemoveTemporaryCollection(PlayerName!); - _ipcManager.PenumbraSetTemporaryMods(PlayerName!, moddedPaths, _cachedData.ManipulationData); + _ipcManager.PenumbraRemoveTemporaryCollection(_logger, applicationId, PlayerName!); + _ipcManager.PenumbraSetTemporaryMods(_logger, applicationId, PlayerName!, moddedPaths, manipulationData); } - private async Task ApplyCustomizationData(ObjectKind objectKind) + private async Task ApplyCustomizationData(Guid applicationId, KeyValuePair> changes, API.Data.CharacterData charaData) { if (PlayerCharacter == IntPtr.Zero) return; - _cachedData.GlamourerData.TryGetValue(objectKind, out var glamourerData); + + var handler = changes.Key switch + { + ObjectKind.Player => _currentOtherChara!, + ObjectKind.Companion => _gameObjectHandlerFactory.Create(changes.Key, () => _dalamudUtil.GetCompanion(PlayerCharacter), false), + ObjectKind.MinionOrMount => _gameObjectHandlerFactory.Create(changes.Key, () => _dalamudUtil.GetMinionOrMount(PlayerCharacter) ?? IntPtr.Zero, false), + ObjectKind.Pet => _gameObjectHandlerFactory.Create(changes.Key, () => _dalamudUtil.GetPet(PlayerCharacter), false), + _ => throw new NotSupportedException("ObjectKind not supported: " + changes.Key) + }; CancellationTokenSource applicationTokenSource = new(); applicationTokenSource.CancelAfter(TimeSpan.FromSeconds(30)); - switch (objectKind) + if (handler.Address == IntPtr.Zero) return; + + _logger.LogDebug($"[{applicationId}] Applying Customization Data for {handler}"); + _dalamudUtil.WaitWhileCharacterIsDrawing(_logger, handler, applicationId, 30000); + + foreach (var change in changes.Value) { - case ObjectKind.Player: - _dalamudUtil.WaitWhileCharacterIsDrawing(_currentOtherChara!, 30000); - _ipcManager.HeelsSetOffsetForPlayer(_cachedData.HeelsOffset, PlayerCharacter); - _ipcManager.CustomizePlusSetBodyScale(PlayerCharacter, _cachedData.CustomizePlusData); - _ipcManager.PalettePlusSetPalette(PlayerCharacter, _cachedData.PalettePlusData); - Logger.Debug($"Request Redraw for {PlayerName}"); - if (_ipcManager.CheckGlamourerApi() && !string.IsNullOrEmpty(glamourerData)) - { - await _ipcManager.GlamourerApplyAll(glamourerData, _currentOtherChara!, applicationTokenSource.Token).ConfigureAwait(false); - } - else - { - await _ipcManager.PenumbraRedraw(_currentOtherChara!, applicationTokenSource.Token).ConfigureAwait(false); - } - break; - - case ObjectKind.MinionOrMount: - { - var minionOrMount = _dalamudUtil.GetMinionOrMount(PlayerCharacter); - if (minionOrMount != null) - { - using GameObjectHandler tempHandler = new(Mediator, ObjectKind.MinionOrMount, - () => minionOrMount.Value, false); - - Logger.Debug($"Request Redraw for {PlayerName} Minion/Mount"); - _dalamudUtil.WaitWhileCharacterIsDrawing(tempHandler, 30000); - if (_ipcManager.CheckGlamourerApi() && !string.IsNullOrEmpty(glamourerData)) - { - await _ipcManager.GlamourerApplyAll(glamourerData, tempHandler, applicationTokenSource.Token).ConfigureAwait(false); - } - else - { - await _ipcManager.PenumbraRedraw(tempHandler, applicationTokenSource.Token).ConfigureAwait(false); - } - } - + _logger.LogDebug($"[{applicationId}] Processing {change} for {handler}"); + switch (change) + { + case PlayerChanges.Palette: + _ipcManager.PalettePlusSetPalette(handler.Address, charaData.PalettePlusData); break; - } - - case ObjectKind.Pet: - { - int tick = 16; - var pet = _dalamudUtil.GetPet(PlayerCharacter); - if (pet != IntPtr.Zero) - { - var totalWait = 0; - var newPet = IntPtr.Zero; - const int maxWait = 3000; - Logger.Debug($"Request Redraw for {PlayerName} Pet"); - - do - { - Thread.Sleep(tick); - totalWait += tick; - newPet = _dalamudUtil.GetPet(PlayerCharacter); - } while (newPet == pet && totalWait < maxWait); - - using var tempHandler = new GameObjectHandler(Mediator, ObjectKind.Pet, () => newPet, false); - - if (_ipcManager.CheckGlamourerApi() && !string.IsNullOrEmpty(glamourerData)) - { - await _ipcManager.GlamourerApplyAll(glamourerData, tempHandler, applicationTokenSource.Token).ConfigureAwait(false); - } - else - { - await _ipcManager.PenumbraRedraw(tempHandler, applicationTokenSource.Token).ConfigureAwait(false); - } - } - + case PlayerChanges.Customize: + _ipcManager.CustomizePlusSetBodyScale(handler.Address, charaData.CustomizePlusData); break; - } - - case ObjectKind.Companion: - { - var companion = _dalamudUtil.GetCompanion(PlayerCharacter); - if (companion != IntPtr.Zero) - { - Logger.Debug($"Request Redraw for {PlayerName} Companion"); - - using GameObjectHandler tempHandler = new(Mediator, ObjectKind.Companion, () => companion, false); - - _dalamudUtil.WaitWhileCharacterIsDrawing(tempHandler, 30000); - if (_ipcManager.CheckGlamourerApi() && !string.IsNullOrEmpty(glamourerData)) - { - await _ipcManager.GlamourerApplyAll(glamourerData, tempHandler, applicationTokenSource.Token).ConfigureAwait(false); - } - else - { - await _ipcManager.PenumbraRedraw(tempHandler, applicationTokenSource.Token).ConfigureAwait(false); - } - } - + case PlayerChanges.Heels: + _ipcManager.HeelsSetOffsetForPlayer(charaData.HeelsOffset, handler.Address); break; - } + case PlayerChanges.Mods: + if (charaData.GlamourerData.TryGetValue(changes.Key, out var glamourerData)) + { + await _ipcManager.GlamourerApplyAll(_logger, handler, glamourerData, applicationId, applicationTokenSource.Token).ConfigureAwait(false); + } + else + { + await _ipcManager.PenumbraRedraw(_logger, handler, applicationId, applicationTokenSource.Token).ConfigureAwait(false); + } + break; + } } } - private void DownloadAndApplyCharacter(API.Data.CharacterData charaData, List objectKind, bool updateModdedPaths) + private void DownloadAndApplyCharacter(API.Data.CharacterData charaData, Dictionary> updatedData) { - if (!objectKind.Any()) + if (!updatedData.Any()) { - Logger.Debug("Nothing to update for " + this); + _logger.LogDebug("Nothing to update for " + this); } + var updateModdedPaths = updatedData.Values.Any(v => v.Any(p => p == PlayerChanges.Mods)); + _downloadCancellationTokenSource?.Cancel(); _downloadCancellationTokenSource?.Dispose(); _downloadCancellationTokenSource = new CancellationTokenSource(); @@ -403,7 +352,7 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable { downloadId = _apiController.GetDownloadId(); - Logger.Debug("Downloading missing files for player " + PlayerName + ", kind: " + objectKind); + _logger.LogDebug("Downloading missing files for player " + PlayerName + ", kind: " + updatedData); if (toDownloadReplacements.Any()) { await _apiController.DownloadFiles(downloadId, toDownloadReplacements, downloadToken).ConfigureAwait(false); @@ -412,7 +361,7 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable if (downloadToken.IsCancellationRequested) { - Logger.Verbose("Detected cancellation"); + _logger.LogTrace("Detected cancellation"); return; } @@ -428,21 +377,24 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable while (!_applicationTask?.IsCompleted ?? false) { // block until current application is done - Logger.Debug("Waiting for current data application to finish"); + _logger.LogDebug("Waiting for current data application to finish"); await Task.Delay(250).ConfigureAwait(false); if (downloadToken.IsCancellationRequested) return; } _applicationTask = Task.Run(async () => { - if (moddedPaths.Any()) + Guid applicationId = Guid.NewGuid(); + _logger.LogDebug($"[{applicationId}] Starting application task"); + + if (updateModdedPaths) { - ApplyBaseData(moddedPaths); + ApplyBaseData(applicationId, moddedPaths, charaData.ManipulationData); } - foreach (var kind in objectKind) + foreach (var kind in updatedData) { - await ApplyCustomizationData(kind).ConfigureAwait(false); + await ApplyCustomizationData(applicationId, kind, charaData).ConfigureAwait(false); } }); @@ -452,7 +404,7 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable if (!task.IsCanceled) return; - Logger.Debug("Application was cancelled"); + _logger.LogDebug("Application was cancelled"); _apiController.CancelDownload(downloadId); }); } @@ -473,28 +425,33 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable Task.Run(async () => { - _dalamudUtil.WaitWhileCharacterIsDrawing(_currentOtherChara!, ct: token); - Logger.Debug("Unauthorized character change detected"); - await ApplyCustomizationData(ObjectKind.Player).ConfigureAwait(false); + var applicationId = Guid.NewGuid(); + _dalamudUtil.WaitWhileCharacterIsDrawing(_logger, _currentOtherChara!, applicationId, ct: token); + _logger.LogDebug("Unauthorized character change detected"); + await ApplyCustomizationData(applicationId, new(ObjectKind.Player, + new HashSet(new[] { PlayerChanges.Palette, PlayerChanges.Customize, PlayerChanges.Heels, PlayerChanges.Mods })), + _cachedData).ConfigureAwait(false); }, token); } - private async Task RevertCustomizationData(ObjectKind objectKind) + private async Task RevertCustomizationData(ObjectKind objectKind, string name, Guid applicationId) { if (PlayerCharacter == IntPtr.Zero) return; var cancelToken = new CancellationTokenSource(); cancelToken.CancelAfter(TimeSpan.FromSeconds(10)); + _logger.LogDebug($"[{applicationId}] Reverting all Customization for {OnlineUser.User.AliasOrUID}/{name} {objectKind}"); + if (objectKind == ObjectKind.Player) { - Logger.Debug($"Restoring Customization for {OnlineUser.User.AliasOrUID}/{PlayerName}: {_originalGlamourerData}"); - await _ipcManager.GlamourerApplyOnlyCustomization(_originalGlamourerData, _currentOtherChara!, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); - Logger.Debug($"Restoring Equipment for {OnlineUser.User.AliasOrUID}/{PlayerName}: {_lastGlamourerData}"); - await _ipcManager.GlamourerApplyOnlyEquipment(_lastGlamourerData, _currentOtherChara!, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); - Logger.Debug($"Restoring Heels for {OnlineUser.User.AliasOrUID}/{PlayerName}"); + _logger.LogDebug($"[{applicationId}] Restoring Customization for {OnlineUser.User.AliasOrUID}/{name}: {_originalGlamourerData}"); + await _ipcManager.GlamourerApplyOnlyCustomization(_logger, _currentOtherChara!, _originalGlamourerData, applicationId, cancelToken.Token, fireAndForget: false).ConfigureAwait(false); + _logger.LogDebug($"[{applicationId}] Restoring Equipment for {OnlineUser.User.AliasOrUID}/{name}: {_lastGlamourerData}"); + await _ipcManager.GlamourerApplyOnlyEquipment(_logger, _currentOtherChara!, _lastGlamourerData, applicationId, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); + _logger.LogDebug($"[{applicationId}] Restoring Heels for {OnlineUser.User.AliasOrUID}/{name}"); _ipcManager.HeelsRestoreOffsetForPlayer(PlayerCharacter); - Logger.Debug($"Restoring C+ for {OnlineUser.User.AliasOrUID}/{PlayerName}"); + _logger.LogDebug($"[{applicationId}] Restoring C+ for {OnlineUser.User.AliasOrUID}/{name}"); _ipcManager.CustomizePlusRevert(PlayerCharacter); _ipcManager.PalettePlusRemovePalette(PlayerCharacter); } @@ -503,9 +460,9 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable var minionOrMount = _dalamudUtil.GetMinionOrMount(PlayerCharacter); if (minionOrMount != null) { - using GameObjectHandler tempHandler = new(Mediator, ObjectKind.MinionOrMount, () => minionOrMount.Value, + using GameObjectHandler tempHandler = _gameObjectHandlerFactory.Create(ObjectKind.MinionOrMount, () => minionOrMount.Value, false); - await _ipcManager.PenumbraRedraw(tempHandler, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); + await _ipcManager.PenumbraRedraw(_logger, tempHandler, applicationId, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); } } else if (objectKind == ObjectKind.Pet) @@ -513,9 +470,9 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable var pet = _dalamudUtil.GetPet(PlayerCharacter); if (pet != IntPtr.Zero) { - using GameObjectHandler tempHandler = new(Mediator, ObjectKind.Pet, () => pet, + using GameObjectHandler tempHandler = _gameObjectHandlerFactory.Create(ObjectKind.Pet, () => pet, false); - await _ipcManager.PenumbraRedraw(tempHandler, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); + await _ipcManager.PenumbraRedraw(_logger, tempHandler, applicationId, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); } } else if (objectKind == ObjectKind.Companion) @@ -523,9 +480,9 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable var companion = _dalamudUtil.GetCompanion(PlayerCharacter); if (companion != IntPtr.Zero) { - using GameObjectHandler tempHandler = new(Mediator, ObjectKind.Pet, () => companion, + using GameObjectHandler tempHandler = _gameObjectHandlerFactory.Create(ObjectKind.Pet, () => companion, false); - await _ipcManager.PenumbraRedraw(tempHandler, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); + await _ipcManager.PenumbraRedraw(_logger, tempHandler, applicationId, cancelToken.Token, fireAndForget: true).ConfigureAwait(false); } } } @@ -547,17 +504,17 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable } else { - Logger.Verbose("Missing file: " + item.Hash); + _logger.LogTrace("Missing file: " + item.Hash); missingFiles.Add(item); } } } - foreach (var item in _cachedData.FileReplacements.SelectMany(k => k.Value.Where(v => !string.IsNullOrEmpty(v.FileSwapPath))).ToList()) + foreach (var item in charaData.FileReplacements.SelectMany(k => k.Value.Where(v => !string.IsNullOrEmpty(v.FileSwapPath))).ToList()) { foreach (var gamePath in item.GamePaths) { - Logger.Verbose("Adding file swap for " + gamePath + ":" + item.FileSwapPath); + _logger.LogTrace("Adding file swap for " + gamePath + ":" + item.FileSwapPath); moddedDictionary[gamePath] = item.FileSwapPath; } } @@ -566,7 +523,7 @@ public class CachedPlayer : MediatorSubscriberBase, IDisposable { PluginLog.Error(ex, "Something went wrong during calculation replacements"); } - Logger.Debug("ModdedPaths calculated, missing files: " + missingFiles.Count); + _logger.LogDebug("ModdedPaths calculated, missing files: " + missingFiles.Count); return missingFiles; } } \ No newline at end of file diff --git a/MareSynchronos/Managers/IpcManager.cs b/MareSynchronos/Managers/IpcManager.cs index 37b06ae..ffeb6ef 100644 --- a/MareSynchronos/Managers/IpcManager.cs +++ b/MareSynchronos/Managers/IpcManager.cs @@ -10,6 +10,7 @@ using Penumbra.Api.Helpers; using MareSynchronos.Mediator; using Dalamud.Interface.Internal.Notifications; using MareSynchronos.Models; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Managers; @@ -59,7 +60,6 @@ public class IpcManager : MediatorSubscriberBase, IDisposable private readonly ICallGateSubscriber _palettePlusSetCharaPalette; private readonly ICallGateSubscriber _palettePlusRemoveCharaPalette; private readonly ICallGateSubscriber _palettePlusPaletteChanged; - private readonly DalamudUtil _dalamudUtil; private bool _inGposeQueueMode = false; private ConcurrentQueue ActionQueue => _inGposeQueueMode ? _gposeActionQueue : _normalQueue; @@ -75,9 +75,11 @@ public class IpcManager : MediatorSubscriberBase, IDisposable private bool _heelsAvailable = false; private bool _palettePlusAvailable = false; - public IpcManager(DalamudPluginInterface pi, DalamudUtil dalamudUtil, MareMediator mediator) : base(mediator) + public IpcManager(ILogger logger, DalamudPluginInterface pi, DalamudUtil dalamudUtil, MareMediator mediator) : base(logger, mediator) { - Logger.Verbose("Creating " + nameof(IpcManager)); + _dalamudUtil = dalamudUtil; + + _logger.LogTrace("Creating " + nameof(IpcManager)); _penumbraInit = Penumbra.Api.Ipc.Initialized.Subscriber(pi, () => PenumbraInit()); _penumbraDispose = Penumbra.Api.Ipc.Disposed.Subscriber(pi, () => PenumbraDispose()); @@ -140,7 +142,6 @@ public class IpcManager : MediatorSubscriberBase, IDisposable Mediator.Publish(new PenumbraInitializedMessage()); } - _dalamudUtil = dalamudUtil; Mediator.Subscribe(this, (_) => HandleActionQueue()); Mediator.Subscribe(this, (_) => HandleGposeActionQueue()); Mediator.Subscribe(this, (_) => ClearActionQueue()); @@ -162,7 +163,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable if (_gposeActionQueue.TryDequeue(out var action)) { if (action == null) return; - Logger.Debug("Execution action in gpose queue: " + action.Method); + _logger.LogDebug("Execution action in gpose queue: " + action.Method); action(); } } @@ -194,7 +195,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable if (ActionQueue.TryDequeue(out var action)) { if (action == null) return; - Logger.Debug("Execution action in queue: " + action.Method); + _logger.LogDebug("Execution action in queue: " + action.Method); action(); } } @@ -305,7 +306,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable int totalSleepTime = 0; while (!ActionQueue.IsEmpty && totalSleepTime < 2000) { - Logger.Verbose("Waiting for actionqueue to clear..."); + _logger.LogTrace("Waiting for actionqueue to clear..."); HandleActionQueue(); Thread.Sleep(16); totalSleepTime += 16; @@ -313,7 +314,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable if (totalSleepTime >= 2000) { - Logger.Verbose("Action queue clear or not, disposing"); + _logger.LogTrace("Action queue clear or not, disposing"); } ActionQueue.Clear(); @@ -340,7 +341,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable var gameObj = _dalamudUtil.CreateGameObject(character); if (gameObj != null) { - Logger.Verbose("Applying Heels data to " + character.ToString("X")); + _logger.LogTrace("Applying Heels data to " + character.ToString("X")); _heelsRegisterPlayer.InvokeAction(gameObj, offset); } }); @@ -354,7 +355,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable var gameObj = _dalamudUtil.CreateGameObject(character); if (gameObj != null) { - Logger.Verbose("Restoring Heels data to " + character.ToString("X")); + _logger.LogTrace("Restoring Heels data to " + character.ToString("X")); _heelsUnregisterPlayer.InvokeAction(gameObj); } }); @@ -377,7 +378,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable if (gameObj is Character c) { string decodedScale = Encoding.UTF8.GetString(Convert.FromBase64String(scale)); - Logger.Verbose("CustomizePlus applying for " + c.Address.ToString("X")); + _logger.LogTrace("CustomizePlus applying for " + c.Address.ToString("X")); _customizePlusSetBodyScaleToCharacter!.InvokeAction(decodedScale, c); } }); @@ -391,13 +392,13 @@ public class IpcManager : MediatorSubscriberBase, IDisposable var gameObj = _dalamudUtil.CreateGameObject(character); if (gameObj is Character c) { - Logger.Verbose("CustomizePlus reverting for " + c.Address.ToString("X")); + _logger.LogTrace("CustomizePlus reverting for " + c.Address.ToString("X")); _customizePlusRevert!.InvokeAction(c); } }); } - private async Task PenumbraRedrawAction(GameObjectHandler obj, Action action, CancellationToken token, bool fireAndForget) + private async Task PenumbraRedrawAction(Microsoft.Extensions.Logging.ILogger logger, GameObjectHandler obj, Guid applicationId, Action action, CancellationToken token, bool fireAndForget) { Mediator.Publish(new PenumbraStartRedrawMessage(obj.Address)); @@ -413,7 +414,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable await Task.Delay(TimeSpan.FromSeconds(1)).ConfigureAwait(false); if (!combinedToken.IsCancellationRequested) - _dalamudUtil.WaitWhileCharacterIsDrawing(obj, 30000, combinedToken); + _dalamudUtil.WaitWhileCharacterIsDrawing(logger, obj, applicationId, 30000, combinedToken); _penumbraRedrawRequests[obj.Address] = false; } @@ -421,33 +422,33 @@ public class IpcManager : MediatorSubscriberBase, IDisposable } - public async Task GlamourerApplyAll(string? customization, GameObjectHandler handler, CancellationToken token, bool fireAndForget = false) + public async Task GlamourerApplyAll(ILogger logger, GameObjectHandler handler, string? customization, Guid applicationId, CancellationToken token, bool fireAndForget = false) { if (!CheckGlamourerApi() || string.IsNullOrEmpty(customization)) return; var gameObj = _dalamudUtil.CreateGameObject(handler.Address); if (gameObj is Character c) { - await PenumbraRedrawAction(handler, () => _glamourerApplyAll!.InvokeAction(customization, c), token, fireAndForget).ConfigureAwait(false); + await PenumbraRedrawAction(logger, handler, applicationId, () => _glamourerApplyAll!.InvokeAction(customization, c), token, fireAndForget).ConfigureAwait(false); } } - public async Task GlamourerApplyOnlyEquipment(string customization, GameObjectHandler handler, CancellationToken token, bool fireAndForget = false) + public async Task GlamourerApplyOnlyEquipment(ILogger logger, GameObjectHandler handler, string customization, Guid applicationId, CancellationToken token, bool fireAndForget = false) { if (!CheckGlamourerApi() || string.IsNullOrEmpty(customization)) return; var gameObj = _dalamudUtil.CreateGameObject(handler.Address); if (gameObj is Character c) { - await PenumbraRedrawAction(handler, () => _glamourerApplyOnlyEquipment!.InvokeAction(customization, c), token, fireAndForget).ConfigureAwait(false); + await PenumbraRedrawAction(logger, handler, applicationId, () => _glamourerApplyOnlyEquipment!.InvokeAction(customization, c), token, fireAndForget).ConfigureAwait(false); } } - public async Task GlamourerApplyOnlyCustomization(string customization, GameObjectHandler handler, CancellationToken token, bool fireAndForget = false) + public async Task GlamourerApplyOnlyCustomization(ILogger logger, GameObjectHandler handler, string customization, Guid applicationId, CancellationToken token, bool fireAndForget = false) { if (!CheckGlamourerApi() || string.IsNullOrEmpty(customization)) return; var gameObj = _dalamudUtil.CreateGameObject(handler.Address); if (gameObj is Character c) { - await PenumbraRedrawAction(handler, () => _glamourerApplyOnlyCustomization!.InvokeAction(customization, c), token, fireAndForget).ConfigureAwait(false); + await PenumbraRedrawAction(logger, handler, applicationId, () => _glamourerApplyOnlyCustomization!.InvokeAction(customization, c), token, fireAndForget).ConfigureAwait(false); } } @@ -494,27 +495,27 @@ public class IpcManager : MediatorSubscriberBase, IDisposable return _penumbraResolveModDir!.Invoke().ToLowerInvariant(); } - public async Task PenumbraRedraw(GameObjectHandler handler, CancellationToken token, bool fireAndForget = false) + public async Task PenumbraRedraw(ILogger logger, GameObjectHandler handler, Guid applicationId, CancellationToken token, bool fireAndForget = false) { if (!CheckPenumbraApi()) return; var gameObj = _dalamudUtil.CreateGameObject(handler.Address); if (gameObj is Character c) { - await PenumbraRedrawAction(handler, () => _penumbraRedrawObject!.Invoke(c, RedrawType.Redraw), token, fireAndForget).ConfigureAwait(false); + await PenumbraRedrawAction(logger, handler, applicationId, () => _penumbraRedrawObject!.Invoke(c, RedrawType.Redraw), token, fireAndForget).ConfigureAwait(false); } } - public void PenumbraRemoveTemporaryCollection(string characterName) + public void PenumbraRemoveTemporaryCollection(ILogger logger, Guid applicationId, string characterName) { if (!CheckPenumbraApi()) return; ActionQueue.Enqueue(() => { var collName = "Mare_" + characterName; - Logger.Verbose("Removing temp collection for " + collName); + logger.LogTrace($"[{applicationId}] Removing temp collection for {collName}"); var ret = _penumbraRemoveTemporaryMod.Invoke("MareChara", collName, 0); - Logger.Verbose("RemoveTemporaryMod: " + ret); + logger.LogTrace($"[{applicationId}] RemoveTemporaryMod: {ret}"); var ret2 = _penumbraRemoveTemporaryCollection.Invoke(collName); - Logger.Verbose("RemoveTemporaryCollection: " + ret2); + logger.LogTrace($"[{applicationId}] RemoveTemporaryCollection: {ret2}"); }); } @@ -536,7 +537,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable return resolvedPaths; } - public void PenumbraSetTemporaryMods(string characterName, Dictionary modPaths, string manipulationData) + public void PenumbraSetTemporaryMods(ILogger logger, Guid applicationId, string characterName, Dictionary modPaths, string manipulationData) { if (!CheckPenumbraApi()) return; @@ -549,16 +550,16 @@ public class IpcManager : MediatorSubscriberBase, IDisposable } var collName = "Mare_" + characterName; var ret = _penumbraCreateNamedTemporaryCollection.Invoke(collName); - Logger.Verbose("Creating Temp Collection " + collName + ", Success: " + ret); + logger.LogTrace($"[{applicationId}] Creating Temp Collection {collName}, Success: {ret}"); var retAssign = _penumbraAssignTemporaryCollection.Invoke(collName, idx.Value, c: true); - Logger.Verbose("Assigning Temp Collection " + collName + " to index " + idx.Value); + logger.LogTrace($"[{applicationId}] Assigning Temp Collection {collName} to index {idx.Value}"); foreach (var mod in modPaths) { - Logger.Verbose(mod.Key + " => " + mod.Value); + logger.LogTrace($"[{applicationId}] {mod.Key} => {mod.Value}"); } var ret2 = _penumbraAddTemporaryMod.Invoke("MareChara", collName, modPaths, manipulationData, 0); - Logger.Verbose("Setting temp mods for " + collName + ", Success: " + ret2); + logger.LogTrace($"[{applicationId}] Setting temp mods for {collName}, Success: {ret2}"); }); } @@ -616,12 +617,12 @@ public class IpcManager : MediatorSubscriberBase, IDisposable if (string.IsNullOrEmpty(decodedPalette)) { - Logger.Verbose("PalettePlus removing for " + c.Address.ToString("X")); + _logger.LogTrace("PalettePlus removing for " + c.Address.ToString("X")); _palettePlusRemoveCharaPalette!.InvokeAction(c); } else { - Logger.Verbose("PalettePlus applying for " + c.Address.ToString("X")); + _logger.LogTrace("PalettePlus applying for " + c.Address.ToString("X")); _palettePlusSetCharaPalette!.InvokeAction(c, decodedPalette); } } @@ -644,7 +645,7 @@ public class IpcManager : MediatorSubscriberBase, IDisposable var gameObj = _dalamudUtil.CreateGameObject(character); if (gameObj is Character c) { - Logger.Verbose("PalettePlus removing for " + c.Address.ToString("X")); + _logger.LogTrace("PalettePlus removing for " + c.Address.ToString("X")); _palettePlusRemoveCharaPalette!.InvokeAction(c); } }); diff --git a/MareSynchronos/Managers/NotificationService.cs b/MareSynchronos/Managers/NotificationService.cs index a429df6..975dbe8 100644 --- a/MareSynchronos/Managers/NotificationService.cs +++ b/MareSynchronos/Managers/NotificationService.cs @@ -5,7 +5,7 @@ using Dalamud.Interface.Internal.Notifications; using MareSynchronos.MareConfiguration; using MareSynchronos.MareConfiguration.Models; using MareSynchronos.Mediator; -using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Managers; public class NotificationService : MediatorSubscriberBase @@ -14,7 +14,7 @@ public class NotificationService : MediatorSubscriberBase private readonly ChatGui _chatGui; private readonly MareConfigService _configurationService; - public NotificationService(MareMediator mediator, UiBuilder uiBuilder, ChatGui chatGui, MareConfigService configurationService) : base(mediator) + public NotificationService(ILogger logger, MareMediator mediator, UiBuilder uiBuilder, ChatGui chatGui, MareConfigService configurationService) : base(logger, mediator) { _uiBuilder = uiBuilder; _chatGui = chatGui; @@ -24,7 +24,7 @@ public class NotificationService : MediatorSubscriberBase private void ShowNotification(NotificationMessage msg) { - Logger.Info(msg.ToString()); + _logger.LogInformation(msg.ToString()); switch (msg.Type) { diff --git a/MareSynchronos/Managers/OnlinePlayerManager.cs b/MareSynchronos/Managers/OnlinePlayerManager.cs index 079265e..1fc425c 100644 --- a/MareSynchronos/Managers/OnlinePlayerManager.cs +++ b/MareSynchronos/Managers/OnlinePlayerManager.cs @@ -3,6 +3,7 @@ using MareSynchronos.FileCache; using MareSynchronos.Mediator; using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Managers; @@ -14,32 +15,29 @@ public class OnlinePlayerManager : MediatorSubscriberBase, IDisposable private readonly PairManager _pairManager; private CharacterData? _lastSentData; - public OnlinePlayerManager(ApiController apiController, DalamudUtil dalamudUtil, - FileCacheManager fileDbManager, PairManager pairManager, MareMediator mediator) : base(mediator) + public OnlinePlayerManager(ILogger logger, ApiController apiController, DalamudUtil dalamudUtil, + FileCacheManager fileDbManager, PairManager pairManager, MareMediator mediator) : base(logger, mediator) { - Logger.Verbose("Creating " + nameof(OnlinePlayerManager)); - + _logger.LogTrace("Creating " + nameof(OnlinePlayerManager)); _apiController = apiController; _dalamudUtil = dalamudUtil; _fileDbManager = fileDbManager; _pairManager = pairManager; Mediator.Subscribe(this, (msg) => PlayerManagerOnPlayerHasChanged((PlayerChangedMessage)msg)); - Mediator.Subscribe(this, (_) => DalamudUtilOnLogIn()); - Mediator.Subscribe(this, (_) => DalamudUtilOnLogOut()); Mediator.Subscribe(this, (_) => FrameworkOnUpdate()); Mediator.Subscribe(this, (msg) => { var newData = ((CharacterDataCreatedMessage)msg).CharacterData.ToAPI(); if (_lastSentData == null || _lastSentData != null && !string.Equals(newData.DataHash.Value, _lastSentData.DataHash.Value, StringComparison.Ordinal)) { - Logger.Debug("Pushing data for visible players"); + _logger.LogDebug("Pushing data for visible players"); _lastSentData = newData; PushCharacterData(_pairManager.VisibleUsers); } else { - Logger.Debug("Not sending data for " + newData.DataHash.Value); + _logger.LogDebug("Not sending data for " + newData.DataHash.Value); } }); } @@ -49,16 +47,6 @@ public class OnlinePlayerManager : MediatorSubscriberBase, IDisposable PushCharacterData(_pairManager.VisibleUsers); } - private void DalamudUtilOnLogIn() - { - Mediator.Subscribe(this, (_) => FrameworkOnUpdate()); - } - - private void DalamudUtilOnLogOut() - { - Mediator.Unsubscribe(this); - } - public override void Dispose() { base.Dispose(); @@ -83,7 +71,7 @@ public class OnlinePlayerManager : MediatorSubscriberBase, IDisposable if (newVisiblePlayers.Any()) { - Logger.Verbose("Has new visible players, pushing character data"); + _logger.LogTrace("Has new visible players, pushing character data"); PushCharacterData(newVisiblePlayers); } } diff --git a/MareSynchronos/Managers/PairManager.cs b/MareSynchronos/Managers/PairManager.cs index a626a22..1129813 100644 --- a/MareSynchronos/Managers/PairManager.cs +++ b/MareSynchronos/Managers/PairManager.cs @@ -12,6 +12,7 @@ using MareSynchronos.Mediator; using MareSynchronos.Models; using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; using System.Collections.Concurrent; namespace MareSynchronos.Managers; @@ -24,8 +25,8 @@ public class PairManager : MediatorSubscriberBase, IDisposable private readonly PairFactory _pairFactory; private readonly MareConfigService _configurationService; - public PairManager(CachedPlayerFactory cachedPlayerFactory, PairFactory pairFactory, - MareConfigService configurationService, MareMediator mediator) : base(mediator) + public PairManager(ILogger logger, CachedPlayerFactory cachedPlayerFactory, PairFactory pairFactory, + MareConfigService configurationService, MareMediator mediator) : base(logger, mediator) { _cachedPlayerFactory = cachedPlayerFactory; _pairFactory = pairFactory; @@ -127,7 +128,7 @@ public class PairManager : MediatorSubscriberBase, IDisposable public void ClearPairs() { - Logger.Debug("Clearing all Pairs"); + _logger.LogDebug("Clearing all Pairs"); DisposePairs(); _allClientPairs.Clear(); _allGroups.Clear(); @@ -142,7 +143,7 @@ public class PairManager : MediatorSubscriberBase, IDisposable public void DisposePairs() { - Logger.Debug("Disposing all Pairs"); + _logger.LogDebug("Disposing all Pairs"); foreach (var item in _allClientPairs) { item.Value.CachedPlayer?.Dispose(); diff --git a/MareSynchronos/Managers/ServerConfigurationManager.cs b/MareSynchronos/Managers/ServerConfigurationManager.cs index 71a4151..5e5a5a3 100644 --- a/MareSynchronos/Managers/ServerConfigurationManager.cs +++ b/MareSynchronos/Managers/ServerConfigurationManager.cs @@ -3,6 +3,7 @@ using MareSynchronos.MareConfiguration.Models; using MareSynchronos.Models; using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; using System.Diagnostics; namespace MareSynchronos.Managers; @@ -10,6 +11,7 @@ namespace MareSynchronos.Managers; public class ServerConfigurationManager { private readonly Dictionary _tokenDictionary = new(); + private readonly ILogger _logger; private readonly ServerConfigService _configService; private readonly ServerTagConfigService _serverTagConfig; private readonly NotesConfigService _notesConfig; @@ -29,8 +31,10 @@ public class ServerConfigurationManager return _notesConfig.Current.ServerNotes[CurrentApiUrl]; } - public ServerConfigurationManager(ServerConfigService configService, ServerTagConfigService serverTagConfig, NotesConfigService notesConfig, DalamudUtil dalamudUtil) + public ServerConfigurationManager(ILogger logger, ServerConfigService configService, + ServerTagConfigService serverTagConfig, NotesConfigService notesConfig, DalamudUtil dalamudUtil) { + _logger = logger; _configService = configService; _serverTagConfig = serverTagConfig; _notesConfig = notesConfig; @@ -78,7 +82,7 @@ public class ServerConfigurationManager public void Save() { var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; - Logger.Debug(caller + " Calling config save"); + _logger.LogDebug(caller + " Calling config save"); _configService.Save(); } diff --git a/MareSynchronos/Managers/TransientResourceManager.cs b/MareSynchronos/Managers/TransientResourceManager.cs index 5f254f6..1a91c73 100644 --- a/MareSynchronos/Managers/TransientResourceManager.cs +++ b/MareSynchronos/Managers/TransientResourceManager.cs @@ -3,8 +3,8 @@ using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; using MareSynchronos.Models; using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; using System.Collections.Concurrent; -using System.Linq; namespace MareSynchronos.Managers; @@ -20,7 +20,8 @@ public class TransientResourceManager : MediatorSubscriberBase, IDisposable private ConcurrentDictionary> TransientResources { get; } = new(); private ConcurrentDictionary> SemiTransientResources { get; } = new(); - public TransientResourceManager(TransientConfigService configurationService, DalamudUtil dalamudUtil, MareMediator mediator) : base(mediator) + public TransientResourceManager(ILogger logger, TransientConfigService configurationService, + DalamudUtil dalamudUtil, MareMediator mediator) : base(logger, mediator) { _configurationService = configurationService; _dalamudUtil = dalamudUtil; @@ -35,17 +36,17 @@ public class TransientResourceManager : MediatorSubscriberBase, IDisposable try { - Logger.Debug("Loaded persistent transient resource " + gamePath); + _logger.LogDebug("Loaded persistent transient resource " + gamePath); SemiTransientResources[ObjectKind.Player].Add(gamePath); restored++; } catch (Exception ex) { - Logger.Warn("Error during loading persistent transient resource " + gamePath, ex); + _logger.LogWarning("Error during loading persistent transient resource " + gamePath, ex); } } - Logger.Debug($"Restored {restored}/{gamePaths.Count()} semi persistent resources"); + _logger.LogDebug($"Restored {restored}/{gamePaths.Count()} semi persistent resources"); } Mediator.Subscribe(this, (msg) => Manager_PenumbraResourceLoadEvent((PenumbraResourceLoadMessage)msg)); @@ -59,7 +60,7 @@ public class TransientResourceManager : MediatorSubscriberBase, IDisposable { Task.Run(() => { - Logger.Debug("Penumbra Mod Settings changed, verifying SemiTransientResources"); + _logger.LogDebug("Penumbra Mod Settings changed, verifying SemiTransientResources"); foreach (var item in SemiTransientResources) { Mediator.Publish(new TransientResourceChangedMessage(_dalamudUtil.PlayerPointer)); @@ -81,7 +82,7 @@ public class TransientResourceManager : MediatorSubscriberBase, IDisposable { if (!_dalamudUtil.IsGameObjectPresent(item.Key)) { - Logger.Debug("Object not present anymore: " + item.Key.ToString("X")); + _logger.LogDebug("Object not present anymore: " + item.Key.ToString("X")); TransientResources.TryRemove(item.Key, out _); } } @@ -135,7 +136,7 @@ public class TransientResourceManager : MediatorSubscriberBase, IDisposable } if (!PlayerRelatedPointers.Contains(gameObject)) { - //Logger.Debug("Got resource " + gamePath + " for ptr " + gameObject.ToString("X")); + //_logger.LogDebug("Got resource " + gamePath + " for ptr " + gameObject.ToString("X")); return; } @@ -157,12 +158,12 @@ public class TransientResourceManager : MediatorSubscriberBase, IDisposable if (TransientResources[gameObject].Contains(replacedGamePath) || SemiTransientResources.Any(r => r.Value.Any(f => string.Equals(f, gamePath, StringComparison.OrdinalIgnoreCase)))) { - Logger.Verbose("Not adding " + replacedGamePath + ":" + filePath); + _logger.LogTrace("Not adding " + replacedGamePath + ":" + filePath); } else { TransientResources[gameObject].Add(replacedGamePath); - Logger.Debug($"Adding {replacedGamePath} for {gameObject} ({filePath})"); + _logger.LogDebug($"Adding {replacedGamePath} for {gameObject} ({filePath})"); Mediator.Publish(new TransientResourceChangedMessage(gameObject)); } } @@ -180,7 +181,7 @@ public class TransientResourceManager : MediatorSubscriberBase, IDisposable } var transientResources = resources.ToList(); - Logger.Debug("Persisting " + transientResources.Count + " transient resources"); + _logger.LogDebug("Persisting " + transientResources.Count + " transient resources"); foreach (var gamePath in transientResources) { SemiTransientResources[objectKind].Add(gamePath); diff --git a/MareSynchronos/MareConfiguration/ConfigurationMigrator.cs b/MareSynchronos/MareConfiguration/ConfigurationMigrator.cs index 7b09101..35d5630 100644 --- a/MareSynchronos/MareConfiguration/ConfigurationMigrator.cs +++ b/MareSynchronos/MareConfiguration/ConfigurationMigrator.cs @@ -2,17 +2,19 @@ using MareSynchronos.MareConfiguration.Configurations; using MareSynchronos.MareConfiguration.Configurations.Obsolete; using MareSynchronos.MareConfiguration.Models; -using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; using Newtonsoft.Json; namespace MareSynchronos.MareConfiguration; public class ConfigurationMigrator { + private readonly ILogger _logger; private readonly DalamudPluginInterface _pi; - public ConfigurationMigrator(DalamudPluginInterface pi) + public ConfigurationMigrator(ILogger logger, DalamudPluginInterface pi) { + _logger = logger; _pi = pi; } @@ -21,9 +23,9 @@ public class ConfigurationMigrator #pragma warning disable CS0618 // ignore Obsolete tag, the point of this migrator is to migrate obsolete configs to new ones if (_pi.GetPluginConfig() is Configuration oldConfig) { - Logger.Info("Migrating Configuration from old config style to 1"); + _logger.LogInformation("Migrating Configuration from old config style to 1"); - var config = oldConfig.ToMareConfig(); + var config = oldConfig.ToMareConfig(_logger); File.Move(_pi.ConfigFile.FullName, _pi.ConfigFile.FullName + ".old", overwrite: true); MigrateMareConfigV0ToV1(config); } @@ -41,7 +43,7 @@ public class ConfigurationMigrator private void MigrateMareConfigV0ToV1(MareConfigV0 mareConfigV0) { - Logger.Info("Migrating Configuration from version 0 to 1"); + _logger.LogInformation("Migrating Configuration from version 0 to 1"); if (File.Exists(ConfigurationPath(MareConfigService.ConfigName))) File.Copy(ConfigurationPath(MareConfigService.ConfigName), ConfigurationPath(MareConfigService.ConfigName) + ".migrated." + mareConfigV0.Version + ".bak", true); diff --git a/MareSynchronos/MareConfiguration/ConfigurationServiceBase.cs b/MareSynchronos/MareConfiguration/ConfigurationServiceBase.cs index d3e9368..42e44b1 100644 --- a/MareSynchronos/MareConfiguration/ConfigurationServiceBase.cs +++ b/MareSynchronos/MareConfiguration/ConfigurationServiceBase.cs @@ -1,6 +1,6 @@ using Dalamud.Plugin; using MareSynchronos.MareConfiguration.Configurations; -using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; using Newtonsoft.Json; namespace MareSynchronos.MareConfiguration; @@ -44,7 +44,7 @@ public abstract class ConfigurationServiceBase : IDisposable where T : IMareC var lastWriteTime = GetConfigLastWriteTime(); if (lastWriteTime != _configLastWriteTime) { - Logger.Debug($"Config {ConfigurationName} changed, reloading config"); + //_logger.LogDebug($"Config {ConfigurationName} changed, reloading config"); _currentConfigInternal = LazyConfig(); } } @@ -98,7 +98,7 @@ public abstract class ConfigurationServiceBase : IDisposable where T : IMareC } } - Logger.Debug("Saving dirty config " + ConfigurationName); + //_logger.LogDebug("Saving dirty config " + ConfigurationName); try { @@ -117,7 +117,7 @@ public abstract class ConfigurationServiceBase : IDisposable where T : IMareC public void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + //_logger.LogTrace($"Disposing {GetType()}"); _periodicCheckCts.Cancel(); } } diff --git a/MareSynchronos/MareConfiguration/Configurations/MareConfig.cs b/MareSynchronos/MareConfiguration/Configurations/MareConfig.cs index e494ea4..7e6d76a 100644 --- a/MareSynchronos/MareConfiguration/Configurations/MareConfig.cs +++ b/MareSynchronos/MareConfiguration/Configurations/MareConfig.cs @@ -1,4 +1,5 @@ using MareSynchronos.MareConfiguration.Models; +using Microsoft.Extensions.Logging; namespace MareSynchronos.MareConfiguration.Configurations; @@ -24,4 +25,5 @@ public class MareConfig : IMareConfiguration public NotificationLocation InfoNotification { get; set; } = NotificationLocation.Toast; public NotificationLocation WarningNotification { get; set; } = NotificationLocation.Both; public NotificationLocation ErrorNotification { get; set; } = NotificationLocation.Both; + public LogLevel LogLevel { get; set; } = LogLevel.Information; } diff --git a/MareSynchronos/MareConfiguration/Configurations/Obsolete/Configuration.cs b/MareSynchronos/MareConfiguration/Configurations/Obsolete/Configuration.cs index 7df0072..d1b5a49 100644 --- a/MareSynchronos/MareConfiguration/Configurations/Obsolete/Configuration.cs +++ b/MareSynchronos/MareConfiguration/Configurations/Obsolete/Configuration.cs @@ -1,8 +1,8 @@ using Dalamud.Configuration; using Dalamud.Plugin; using MareSynchronos.MareConfiguration.Models; -using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; namespace MareSynchronos.MareConfiguration.Configurations.Obsolete; @@ -56,28 +56,16 @@ public class Configuration : IPluginConfiguration public HashSet OpenPairTags = new(StringComparer.Ordinal); - // the below exist just to make saving less cumbersome - public void Initialize(DalamudPluginInterface pluginInterface) - { - _pluginInterface = pluginInterface; - - if (!Directory.Exists(CacheFolder)) - { - InitialScanComplete = false; - } - - Save(); - } - public void Save() { _pluginInterface!.SavePluginConfig(this); } - public MareConfigV0 ToMareConfig() + public MareConfigV0 ToMareConfig(ILogger logger) { + MareConfigV0 newConfig = new(); - Logger.Info("Migrating Config to MareConfig"); + logger.LogInformation("Migrating Config to MareConfig"); newConfig.AcceptedAgreement = AcceptedAgreement; newConfig.CacheFolder = CacheFolder; @@ -95,7 +83,7 @@ public class Configuration : IPluginConfiguration // create all server storage based on current clientsecret foreach (var secret in ClientSecret) { - Logger.Debug("Migrating " + secret.Key); + logger.LogDebug("Migrating " + secret.Key); var apiuri = secret.Key; var secretkey = secret.Value; ServerStorageV0 toAdd = new(); diff --git a/MareSynchronos/MareConfiguration/MareConfigService.cs b/MareSynchronos/MareConfiguration/MareConfigService.cs index 60e8009..526509d 100644 --- a/MareSynchronos/MareConfiguration/MareConfigService.cs +++ b/MareSynchronos/MareConfiguration/MareConfigService.cs @@ -1,5 +1,6 @@ using Dalamud.Plugin; using MareSynchronos.MareConfiguration.Configurations; +using Microsoft.Extensions.Logging; namespace MareSynchronos.MareConfiguration; diff --git a/MareSynchronos/MareConfiguration/NotesConfigService.cs b/MareSynchronos/MareConfiguration/NotesConfigService.cs index 3af540d..bc5823e 100644 --- a/MareSynchronos/MareConfiguration/NotesConfigService.cs +++ b/MareSynchronos/MareConfiguration/NotesConfigService.cs @@ -1,5 +1,6 @@ using Dalamud.Plugin; using MareSynchronos.MareConfiguration.Configurations; +using Microsoft.Extensions.Logging; namespace MareSynchronos.MareConfiguration; diff --git a/MareSynchronos/MareConfiguration/ServerConfigService.cs b/MareSynchronos/MareConfiguration/ServerConfigService.cs index 1b566e8..0475c8f 100644 --- a/MareSynchronos/MareConfiguration/ServerConfigService.cs +++ b/MareSynchronos/MareConfiguration/ServerConfigService.cs @@ -1,5 +1,6 @@ using Dalamud.Plugin; using MareSynchronos.MareConfiguration.Configurations; +using Microsoft.Extensions.Logging; namespace MareSynchronos.MareConfiguration; diff --git a/MareSynchronos/MareConfiguration/ServerTagConfigService.cs b/MareSynchronos/MareConfiguration/ServerTagConfigService.cs index 6fdfce5..7527e66 100644 --- a/MareSynchronos/MareConfiguration/ServerTagConfigService.cs +++ b/MareSynchronos/MareConfiguration/ServerTagConfigService.cs @@ -1,5 +1,6 @@ using Dalamud.Plugin; using MareSynchronos.MareConfiguration.Configurations; +using Microsoft.Extensions.Logging; namespace MareSynchronos.MareConfiguration; diff --git a/MareSynchronos/MareConfiguration/TransientConfigService.cs b/MareSynchronos/MareConfiguration/TransientConfigService.cs index 5e8e18e..ba41f87 100644 --- a/MareSynchronos/MareConfiguration/TransientConfigService.cs +++ b/MareSynchronos/MareConfiguration/TransientConfigService.cs @@ -1,5 +1,6 @@ using Dalamud.Plugin; using MareSynchronos.MareConfiguration.Configurations; +using Microsoft.Extensions.Logging; namespace MareSynchronos.MareConfiguration; diff --git a/MareSynchronos/MarePlugin.cs b/MareSynchronos/MarePlugin.cs index 2e8a72d..805553f 100644 --- a/MareSynchronos/MarePlugin.cs +++ b/MareSynchronos/MarePlugin.cs @@ -10,6 +10,7 @@ using MareSynchronos.FileCache; using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; namespace MareSynchronos; @@ -71,7 +72,7 @@ public class MarePlugin : MediatorSubscriberBase, IDisposable private const string _commandName = "/mare"; private IServiceScope? _runtimeServiceScope; - public MarePlugin(ServiceProvider serviceProvider, MareMediator mediator) : base(mediator) + public MarePlugin(ILogger logger, ServiceProvider serviceProvider, MareMediator mediator) : base(logger, mediator) { _serviceProvider = serviceProvider; @@ -98,12 +99,12 @@ public class MarePlugin : MediatorSubscriberBase, IDisposable _runtimeServiceScope?.Dispose(); _serviceProvider.Dispose(); - Logger.Debug("Shut down"); + _logger.LogDebug("Shut down"); } private void DalamudUtilOnLogIn() { - Logger.Debug("Client login"); + _logger?.LogDebug("Client login"); var pi = _serviceProvider.GetRequiredService(); pi.UiBuilder.Draw += Draw; @@ -126,7 +127,8 @@ public class MarePlugin : MediatorSubscriberBase, IDisposable private void DalamudUtilOnLogOut() { - Logger.Debug("Client logout"); + _logger?.LogDebug("Client logout"); + _runtimeServiceScope?.Dispose(); var pi = _serviceProvider.GetRequiredService(); pi.UiBuilder.Draw -= Draw; @@ -144,7 +146,7 @@ public class MarePlugin : MediatorSubscriberBase, IDisposable try { - Logger.Debug("Launching Managers"); + _logger?.LogDebug("Launching Managers"); _runtimeServiceScope?.Dispose(); _runtimeServiceScope = _serviceProvider.CreateScope(); @@ -154,7 +156,7 @@ public class MarePlugin : MediatorSubscriberBase, IDisposable } catch (Exception ex) { - Logger.Warn(ex.Message); + _logger?.LogWarning(ex.Message); } } diff --git a/MareSynchronos/MareSynchronos.csproj b/MareSynchronos/MareSynchronos.csproj index 3217771..ad28697 100644 --- a/MareSynchronos/MareSynchronos.csproj +++ b/MareSynchronos/MareSynchronos.csproj @@ -3,7 +3,7 @@ - 0.7.30 + 0.7.31 https://github.com/Penumbra-Sync/client diff --git a/MareSynchronos/Mediator/MareMediator.cs b/MareSynchronos/Mediator/MareMediator.cs index 90a836a..eece0bc 100644 --- a/MareSynchronos/Mediator/MareMediator.cs +++ b/MareSynchronos/Mediator/MareMediator.cs @@ -1,4 +1,4 @@ -using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Mediator; @@ -7,6 +7,12 @@ public class MareMediator : IDisposable private record MediatorSubscriber(IMediatorSubscriber Subscriber, Action Action); private readonly Dictionary> _subscriberDict = new(); + private readonly ILogger _logger; + + public MareMediator(ILogger logger) + { + _logger = logger; + } public void Subscribe(IMediatorSubscriber subscriber, Action action) where T : IMessage { @@ -38,7 +44,7 @@ public class MareMediator : IDisposable } catch (Exception ex) { - Logger.Error("Error executing " + message.GetType() + " for subscriber " + subscriber + ", removing from Mediator", ex); + _logger.LogCritical("Error executing " + message.GetType() + " for subscriber " + subscriber + ", removing from Mediator", ex); subscribers.RemoveWhere(s => s == subscriber); } } @@ -51,13 +57,13 @@ public class MareMediator : IDisposable { var unSubbed = kvp.Value.RemoveWhere(p => p.Subscriber == subscriber); if (unSubbed > 0) - Logger.Verbose(subscriber + " unsubscribed from " + kvp.Key.Name); + _logger.LogTrace(subscriber + " unsubscribed from " + kvp.Key.Name); } } public void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + _logger.LogTrace($"Disposing {GetType()}"); _subscriberDict.Clear(); } } \ No newline at end of file diff --git a/MareSynchronos/Mediator/MediatorSubscriberBase.cs b/MareSynchronos/Mediator/MediatorSubscriberBase.cs index 1577ae7..4da551b 100644 --- a/MareSynchronos/Mediator/MediatorSubscriberBase.cs +++ b/MareSynchronos/Mediator/MediatorSubscriberBase.cs @@ -1,18 +1,20 @@ -using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Mediator; public abstract class MediatorSubscriberBase : IMediatorSubscriber { + protected ILogger _logger { get; } public MareMediator Mediator { get; } - protected MediatorSubscriberBase(MareMediator mediator) + protected MediatorSubscriberBase(ILogger logger, MareMediator mediator) { + _logger = logger; Mediator = mediator; } public virtual void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + _logger.LogTrace($"Disposing {GetType()}"); Mediator.UnsubscribeAll(this); } } diff --git a/MareSynchronos/Mediator/WindowMediatorSubscriberBase.cs b/MareSynchronos/Mediator/WindowMediatorSubscriberBase.cs index dd7e3c6..946a6eb 100644 --- a/MareSynchronos/Mediator/WindowMediatorSubscriberBase.cs +++ b/MareSynchronos/Mediator/WindowMediatorSubscriberBase.cs @@ -1,19 +1,22 @@ using Dalamud.Interface.Windowing; -using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Mediator; public abstract class WindowMediatorSubscriberBase : Window, IMediatorSubscriber { + protected readonly ILogger _logger; + public MareMediator Mediator { get; } - protected WindowMediatorSubscriberBase(MareMediator mediator, string name) : base(name) + protected WindowMediatorSubscriberBase(ILogger logger, MareMediator mediator, string name) : base(name) { + _logger = logger; Mediator = mediator; } public virtual void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + _logger.LogTrace($"Disposing {GetType()}"); Mediator.UnsubscribeAll(this); } } diff --git a/MareSynchronos/Models/GameObjectHandler.cs b/MareSynchronos/Models/GameObjectHandler.cs index 40d3e8b..2004499 100644 --- a/MareSynchronos/Models/GameObjectHandler.cs +++ b/MareSynchronos/Models/GameObjectHandler.cs @@ -2,10 +2,10 @@ using FFXIVClientStructs.FFXIV.Client.Game.Object; using FFXIVClientStructs.FFXIV.Client.Graphics.Scene; using System.Runtime.InteropServices; -using MareSynchronos.Utils; using Penumbra.String; using MareSynchronos.Mediator; using ObjectKind = MareSynchronos.API.Data.Enum.ObjectKind; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Models; @@ -27,23 +27,10 @@ public class GameObjectHandler : MediatorSubscriberBase public override string ToString() { - return $"{Name} (Addr: {Address.ToString("X")}, DrawObj: {DrawObjectAddress.ToString("X")})"; + return $"{Name} ({Address.ToString("X")},{DrawObjectAddress.ToString("X")})"; } - private IntPtr CurrentAddress - { - get - { - try - { - return _getAddress.Invoke(); - } - catch - { return IntPtr.Zero; } - } - } - - public GameObjectHandler(MareMediator mediator, ObjectKind objectKind, Func getAddress, bool watchedObject = true) : base(mediator) + public GameObjectHandler(ILogger logger, MareMediator mediator, ObjectKind objectKind, Func getAddress, bool watchedObject = true) : base(logger, mediator) { _mediator = mediator; ObjectKind = objectKind; @@ -97,10 +84,9 @@ public class GameObjectHandler : MediatorSubscriberBase private void FrameworkUpdate() { - if (_delayedZoningTask?.IsCompleted ?? true) - { - CheckAndUpdateObject(); - } + if (!_delayedZoningTask?.IsCompleted ?? false) return; + + CheckAndUpdateObject(); } private void ZoneSwitchEnd() @@ -118,7 +104,7 @@ public class GameObjectHandler : MediatorSubscriberBase if (!_sendUpdates || _haltProcessing) return; _zoningCts = new(); - Logger.Debug("Starting Delay After Zoning for " + ObjectKind + " " + Name); + _logger.LogDebug($"[{this}] Starting Delay After Zoning"); _delayedZoningTask = Task.Run(async () => { try @@ -128,7 +114,7 @@ public class GameObjectHandler : MediatorSubscriberBase catch { } finally { - Logger.Debug("Delay complete for " + ObjectKind); + _logger.LogDebug($"[{this}] Delay after zoning complete"); _zoningCts.Dispose(); } }); @@ -145,12 +131,12 @@ public class GameObjectHandler : MediatorSubscriberBase private unsafe void CheckAndUpdateObject() { - var curPtr = CurrentAddress; - bool drawObj = false; + var curPtr = _getAddress.Invoke(); + bool drawObjDiff = false; try { var drawObjAddr = (IntPtr)((GameObject*)curPtr)->GetDrawObject(); - drawObj = drawObjAddr != DrawObjectAddress; + drawObjDiff = drawObjAddr != DrawObjectAddress; DrawObjectAddress = drawObjAddr; IsBeingDrawn = (((CharacterBase*)drawObjAddr)->HasModelInSlotLoaded != 0) @@ -159,7 +145,10 @@ public class GameObjectHandler : MediatorSubscriberBase } catch { - IsBeingDrawn = true; + if (curPtr != IntPtr.Zero) + { + IsBeingDrawn = true; + } } if (_haltProcessing) return; @@ -168,30 +157,29 @@ public class GameObjectHandler : MediatorSubscriberBase { if (_clearCts != null) { - Logger.Debug("Cancelling Clear Task for " + ObjectKind + " " + Name); + _logger.LogDebug($"[{this}] Cancelling Clear Task"); _clearCts?.Cancel(); _clearCts = null; } + bool addrDiff = Address != curPtr; + Address = curPtr; var chara = (Character*)curPtr; - bool addr = Address == IntPtr.Zero || Address != curPtr; - bool equip = CompareAndUpdateEquipByteData(chara->EquipSlotData); - var customize = CompareAndUpdateCustomizeData(chara->CustomizeData); + bool equipDiff = CompareAndUpdateEquipByteData(chara->EquipSlotData); + var customizeDiff = _sendUpdates ? CompareAndUpdateCustomizeData(chara->CustomizeData) : false; var name = new ByteString(chara->GameObject.Name).ToString(); bool nameChange = (!string.Equals(name, Name, StringComparison.Ordinal)); - if (addr || equip || customize || drawObj || nameChange) + if (addrDiff || equipDiff || customizeDiff || drawObjDiff || nameChange) { Name = name; - Logger.Verbose($"{ObjectKind} changed: {Name}, now: {curPtr:X}, {(IntPtr)chara->GameObject.DrawObject:X}"); + _logger.LogTrace($"[{this}] Changed"); - Address = curPtr; - DrawObjectAddress = (IntPtr)chara->GameObject.DrawObject; - if (_sendUpdates && !_doNotSendUpdate && DrawObjectAddress != IntPtr.Zero) + if (_sendUpdates && !_doNotSendUpdate) { - Logger.Debug("Sending CreateCacheObjectMessage for " + ObjectKind); + _logger.LogDebug($"[{this}] Sending CreateCacheObjectMessage"); Mediator.Publish(new CreateCacheForObjectMessage(this)); } - if (equip) + if (equipDiff && !_sendUpdates) { Mediator.Publish(new CharacterChangedMessage(this)); } @@ -201,7 +189,7 @@ public class GameObjectHandler : MediatorSubscriberBase { Address = IntPtr.Zero; DrawObjectAddress = IntPtr.Zero; - Logger.Verbose(ObjectKind + " Changed, DrawObj Zero: " + Name + ", now: " + Address + ", " + DrawObjectAddress); + _logger.LogTrace($"[{this}] Changed -> Null"); if (_sendUpdates && ObjectKind != ObjectKind.Player) { _clearCts?.Cancel(); @@ -215,9 +203,9 @@ public class GameObjectHandler : MediatorSubscriberBase private async Task ClearTask(CancellationToken token) { - Logger.Debug("Running Clear Task for " + ObjectKind); + _logger.LogDebug($"[{this}] Running Clear Task"); await Task.Delay(TimeSpan.FromSeconds(1), token).ConfigureAwait(false); - Logger.Debug("Sending ClearCachedForObjectMessage for " + ObjectKind); + _logger.LogDebug($"[{this}] Sending ClearCachedForObjectMessage"); Mediator.Publish(new ClearCacheForObjectMessage(this)); _clearCts = null; } @@ -237,6 +225,7 @@ public class GameObjectHandler : MediatorSubscriberBase return hasChanges; } + private unsafe bool CompareAndUpdateCustomizeData(byte* customizeData) { bool hasChanges = false; @@ -258,7 +247,7 @@ public class GameObjectHandler : MediatorSubscriberBase { if (HatState != null && !hasChanges) { - Logger.Debug("Not Sending Update, only Hat changed"); + _logger.LogDebug($"[{this}] Not Sending Update, only Hat changed"); _doNotSendUpdate = true; } HatState = newHatState; @@ -270,7 +259,7 @@ public class GameObjectHandler : MediatorSubscriberBase { if (VisorWeaponState != null && !hasChanges) { - Logger.Debug("Not Sending Update, only Visor/Weapon changed"); + _logger.LogDebug($"[{this}] Not Sending Update, only Visor/Weapon changed"); _doNotSendUpdate = true; } VisorWeaponState = newWeaponOrVisorState; diff --git a/MareSynchronos/Models/Pair.cs b/MareSynchronos/Models/Pair.cs index a1dc886..71184bd 100644 --- a/MareSynchronos/Models/Pair.cs +++ b/MareSynchronos/Models/Pair.cs @@ -7,17 +7,20 @@ using MareSynchronos.API.Dto.User; using MareSynchronos.Managers; using MareSynchronos.MareConfiguration; using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.Models; public class Pair { + private readonly ILogger _logger; private readonly MareConfigService _configService; private readonly ServerConfigurationManager _serverConfigurationManager; private OptionalPluginWarning? _pluginWarnings; - public Pair(MareConfigService configService, ServerConfigurationManager serverConfigurationManager) + public Pair(ILogger logger, MareConfigService configService, ServerConfigurationManager serverConfigurationManager) { + _logger = logger; _configService = configService; _serverConfigurationManager = serverConfigurationManager; } @@ -96,10 +99,10 @@ public class Pair private API.Data.CharacterData? RemoveNotSyncedFiles(API.Data.CharacterData? data) { - Logger.Verbose("Removing not synced files"); + _logger.LogTrace("Removing not synced files"); if (data == null || (UserPair != null && UserPair.OtherPermissions.IsPaired())) { - Logger.Verbose("Nothing to remove or user is paired directly"); + _logger.LogTrace("Nothing to remove or user is paired directly"); return data; } @@ -114,7 +117,7 @@ public class Pair if (disableAnimations || disableSounds) { - Logger.Verbose($"Data cleaned up: Animations disabled: {disableAnimations}, Sounds disabled: {disableSounds}"); + _logger.LogTrace($"Data cleaned up: Animations disabled: {disableAnimations}, Sounds disabled: {disableSounds}"); foreach (var kvp in data.FileReplacements) { if (disableSounds) diff --git a/MareSynchronos/Plugin.cs b/MareSynchronos/Plugin.cs index 39c6ccb..0327f32 100644 --- a/MareSynchronos/Plugin.cs +++ b/MareSynchronos/Plugin.cs @@ -18,6 +18,7 @@ using Dalamud.Data; using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; namespace MareSynchronos; @@ -25,13 +26,18 @@ public sealed class Plugin : IDalamudPlugin { private readonly MarePlugin plugin; public string Name => "Mare Synchronos"; + private readonly ILogger _pluginLogger; public Plugin(DalamudPluginInterface pluginInterface, CommandManager commandManager, DataManager gameData, Framework framework, ObjectTable objectTable, ClientState clientState, Condition condition, ChatGui chatGui) { - Logger.Debug("Launching " + Name); - IServiceCollection collection = new ServiceCollection(); + collection.AddLogging(o => + { + o.AddDalamudLogging(); + o.SetMinimumLevel(LogLevel.Trace); + }); + // inject dalamud stuff collection.AddSingleton(pluginInterface); collection.AddSingleton(commandManager); @@ -66,6 +72,7 @@ public sealed class Plugin : IDalamudPlugin collection.AddSingleton(); collection.AddSingleton(); collection.AddSingleton(); + collection.AddSingleton(); collection.AddSingleton(); collection.AddSingleton(); @@ -81,16 +88,20 @@ public sealed class Plugin : IDalamudPlugin var serviceProvider = collection.BuildServiceProvider(new ServiceProviderOptions() { ValidateOnBuild = true, ValidateScopes = true }); + _pluginLogger = serviceProvider.GetRequiredService>(); + _pluginLogger.LogDebug("Launching " + Name); + serviceProvider.GetRequiredService().SetupWithLangCode("en"); serviceProvider.GetRequiredService().UiBuilder.DisableGposeUiHide = true; var mediator = serviceProvider.GetRequiredService(); - plugin = new MarePlugin(serviceProvider, mediator); + var logger = serviceProvider.GetRequiredService>(); + plugin = new MarePlugin(logger, serviceProvider, mediator); } public void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + _pluginLogger.LogTrace($"Disposing {GetType()}"); plugin.Dispose(); } } diff --git a/MareSynchronos/UI/CompactUI.cs b/MareSynchronos/UI/CompactUI.cs index 4f3b03a..52cd56d 100644 --- a/MareSynchronos/UI/CompactUI.cs +++ b/MareSynchronos/UI/CompactUI.cs @@ -16,8 +16,8 @@ using MareSynchronos.Mediator; using MareSynchronos.Models; using MareSynchronos.UI.Components; using MareSynchronos.UI.Handlers; -using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; namespace MareSynchronos.UI; @@ -55,9 +55,9 @@ public class CompactUi : WindowMediatorSubscriberBase, IDisposable private readonly SelectPairForGroupUi _selectPairsForGroupUi; private readonly PairGroupsUi _pairGroupsUi; - public CompactUi(WindowSystem windowSystem, + public CompactUi(ILogger logger, WindowSystem windowSystem, UiShared uiShared, MareConfigService configService, ApiController apiController, PairManager pairManager, - ServerConfigurationManager serverManager, MareMediator mediator) : base(mediator, "###MareSynchronosMainUI") + ServerConfigurationManager serverManager, MareMediator mediator) : base(logger, mediator, "###MareSynchronosMainUI") { #if DEBUG @@ -69,7 +69,7 @@ public class CompactUi : WindowMediatorSubscriberBase, IDisposable var ver = Assembly.GetExecutingAssembly().GetName().Version; this.WindowName = "Mare Synchronos " + ver.Major + "." + ver.Minor + "." + ver.Build + "###MareSynchronosMainUI"; #endif - Logger.Verbose("Creating " + nameof(CompactUi)); + _logger.LogTrace("Creating " + nameof(CompactUi)); _windowSystem = windowSystem; _uiShared = uiShared; diff --git a/MareSynchronos/UI/DownloadUi.cs b/MareSynchronos/UI/DownloadUi.cs index 5137142..7b10daa 100644 --- a/MareSynchronos/UI/DownloadUi.cs +++ b/MareSynchronos/UI/DownloadUi.cs @@ -2,13 +2,14 @@ using Dalamud.Interface.Windowing; using ImGuiNET; using MareSynchronos.MareConfiguration; -using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; namespace MareSynchronos.UI; public class DownloadUi : Window, IDisposable { + private readonly ILogger _logger; private readonly WindowSystem _windowSystem; private readonly MareConfigService _configService; private readonly ApiController _apiController; @@ -17,13 +18,14 @@ public class DownloadUi : Window, IDisposable public void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + _logger.LogTrace($"Disposing {GetType()}"); _windowSystem.RemoveWindow(this); } - public DownloadUi(WindowSystem windowSystem, MareConfigService configService, ApiController apiController, UiShared uiShared) : base("Mare Synchronos Downloads") + public DownloadUi(ILogger logger, WindowSystem windowSystem, MareConfigService configService, ApiController apiController, UiShared uiShared) : base("Mare Synchronos Downloads") { - Logger.Verbose("Creating " + nameof(DownloadUi)); + _logger = logger; + _logger.LogTrace("Creating " + nameof(DownloadUi)); _windowSystem = windowSystem; _configService = configService; _apiController = apiController; diff --git a/MareSynchronos/UI/GposeUi.cs b/MareSynchronos/UI/GposeUi.cs index 06dfb6a..4759bdc 100644 --- a/MareSynchronos/UI/GposeUi.cs +++ b/MareSynchronos/UI/GposeUi.cs @@ -7,6 +7,7 @@ using MareSynchronos.Export; using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; using MareSynchronos.Utils; +using Microsoft.Extensions.Logging; namespace MareSynchronos.UI; @@ -18,9 +19,9 @@ public class GposeUi : WindowMediatorSubscriberBase, IDisposable private readonly FileDialogManager _fileDialogManager; private readonly MareConfigService _configService; - public GposeUi(WindowSystem windowSystem, MareCharaFileManager mareCharaFileManager, + public GposeUi(ILogger logger, WindowSystem windowSystem, MareCharaFileManager mareCharaFileManager, DalamudUtil dalamudUtil, FileDialogManager fileDialogManager, MareConfigService configService, - MareMediator mediator) : base(mediator, "Mare Synchronos Gpose Import UI###MareSynchronosGposeUI") + MareMediator mediator) : base(logger, mediator, "Mare Synchronos Gpose Import UI###MareSynchronosGposeUI") { _windowSystem = windowSystem; _mareCharaFileManager = mareCharaFileManager; diff --git a/MareSynchronos/UI/Handlers/TagHandler.cs b/MareSynchronos/UI/Handlers/TagHandler.cs index f60cdf7..5575303 100644 --- a/MareSynchronos/UI/Handlers/TagHandler.cs +++ b/MareSynchronos/UI/Handlers/TagHandler.cs @@ -1,6 +1,5 @@ using MareSynchronos.API.Dto.User; using MareSynchronos.Managers; -using MareSynchronos.Models; namespace MareSynchronos.UI.Handlers { diff --git a/MareSynchronos/UI/IntroUI.cs b/MareSynchronos/UI/IntroUI.cs index 65306cb..20074e0 100644 --- a/MareSynchronos/UI/IntroUI.cs +++ b/MareSynchronos/UI/IntroUI.cs @@ -2,7 +2,6 @@ using Dalamud.Interface.Colors; using Dalamud.Interface.Windowing; using ImGuiNET; -using MareSynchronos.Utils; using MareSynchronos.Localization; using Dalamud.Utility; using MareSynchronos.FileCache; @@ -11,6 +10,7 @@ using MareSynchronos.Managers; using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; using MareSynchronos.MareConfiguration.Models; +using Microsoft.Extensions.Logging; namespace MareSynchronos.UI; @@ -37,10 +37,10 @@ internal class IntroUi : WindowMediatorSubscriberBase, IDisposable _windowSystem.RemoveWindow(this); } - public IntroUi(WindowSystem windowSystem, UiShared uiShared, MareConfigService configService, - PeriodicFileScanner fileCacheManager, ServerConfigurationManager serverConfigurationManager, MareMediator mareMediator) : base(mareMediator, "Mare Synchronos Setup") + public IntroUi(ILogger logger, WindowSystem windowSystem, UiShared uiShared, MareConfigService configService, + PeriodicFileScanner fileCacheManager, ServerConfigurationManager serverConfigurationManager, MareMediator mareMediator) : base(logger, mareMediator, "Mare Synchronos Setup") { - Logger.Verbose("Creating " + nameof(IntroUi)); + _logger.LogTrace("Creating " + nameof(IntroUi)); _uiShared = uiShared; _configService = configService; diff --git a/MareSynchronos/UI/SettingsUi.cs b/MareSynchronos/UI/SettingsUi.cs index b266ccd..811ed26 100644 --- a/MareSynchronos/UI/SettingsUi.cs +++ b/MareSynchronos/UI/SettingsUi.cs @@ -4,7 +4,6 @@ using Dalamud.Interface.Windowing; using ImGuiNET; using MareSynchronos.WebAPI; using System.Numerics; -using MareSynchronos.Utils; using MareSynchronos.WebAPI.Utils; using Dalamud.Utility; using Newtonsoft.Json; @@ -15,6 +14,7 @@ using MareSynchronos.API.Data.Comparer; using MareSynchronos.MareConfiguration; using MareSynchronos.Mediator; using MareSynchronos.MareConfiguration.Models; +using Microsoft.Extensions.Logging; namespace MareSynchronos.UI; @@ -34,12 +34,12 @@ public class SettingsUi : WindowMediatorSubscriberBase, IDisposable private string _lastTab = string.Empty; private bool _wasOpen = false; - public SettingsUi(WindowSystem windowSystem, + public SettingsUi(ILogger logger, WindowSystem windowSystem, UiShared uiShared, MareConfigService configService, MareCharaFileManager mareCharaFileManager, PairManager pairManager, - ServerConfigurationManager serverConfigurationManager, MareMediator mediator) : base(mediator, "Mare Synchronos Settings") + ServerConfigurationManager serverConfigurationManager, MareMediator mediator) : base(logger, mediator, "Mare Synchronos Settings") { - Logger.Verbose("Creating " + nameof(SettingsUi)); + _logger.LogTrace("Creating " + nameof(SettingsUi)); SizeConstraints = new WindowSizeConstraints() { @@ -564,6 +564,12 @@ public class SettingsUi : WindowMediatorSubscriberBase, IDisposable } } UiShared.AttachToolTip("Use this when reporting mods being rejected from the server."); + + _uiShared.DrawCombo("Log Level", Enum.GetValues(), (l) => l.ToString(), (l) => + { + _configService.Current.LogLevel = l; + _configService.Save(); + }, _configService.Current.LogLevel); } private void DrawBlockedTransfers() @@ -719,7 +725,7 @@ public class SettingsUi : WindowMediatorSubscriberBase, IDisposable } catch (Exception ex) { - Logger.Error("Error saving data", ex); + _logger.LogCritical("Error saving data", ex); } }); }); diff --git a/MareSynchronos/UI/UIShared.cs b/MareSynchronos/UI/UIShared.cs index 2f01ac6..2650f28 100644 --- a/MareSynchronos/UI/UIShared.cs +++ b/MareSynchronos/UI/UIShared.cs @@ -18,6 +18,7 @@ using MareSynchronos.Mediator; using MareSynchronos.Models; using MareSynchronos.Utils; using MareSynchronos.WebAPI; +using Microsoft.Extensions.Logging; namespace MareSynchronos.UI; @@ -60,9 +61,9 @@ public partial class UiShared : MediatorSubscriberBase private bool _heelsExists = false; private bool _palettePlusExists = false; - public UiShared(IpcManager ipcManager, ApiController apiController, PeriodicFileScanner cacheScanner, FileDialogManager fileDialogManager, + public UiShared(ILogger logger, IpcManager ipcManager, ApiController apiController, PeriodicFileScanner cacheScanner, FileDialogManager fileDialogManager, MareConfigService configService, DalamudUtil dalamudUtil, DalamudPluginInterface pluginInterface, Dalamud.Localization localization, - ServerConfigurationManager serverManager, MareMediator mediator) : base(mediator) + ServerConfigurationManager serverManager, MareMediator mediator) : base(logger, mediator) { _ipcManager = ipcManager; _apiController = apiController; @@ -154,13 +155,13 @@ public partial class UiShared : MediatorSubscriberBase } catch (Exception ex) { - Logger.Warn($"Font failed to load. {fontFile}"); - Logger.Warn(ex.ToString()); + _logger.LogWarning($"Font failed to load. {fontFile}"); + _logger.LogWarning(ex.ToString()); } } else { - Logger.Debug($"Font doesn't exist. {fontFile}"); + _logger.LogDebug($"Font doesn't exist. {fontFile}"); } } @@ -693,7 +694,7 @@ public partial class UiShared : MediatorSubscriberBase } catch { - Logger.Warn("Could not parse " + note); + _logger.LogWarning("Could not parse " + note); } } diff --git a/MareSynchronos/Utils/DalamudLogger.cs b/MareSynchronos/Utils/DalamudLogger.cs new file mode 100644 index 0000000..f7093e0 --- /dev/null +++ b/MareSynchronos/Utils/DalamudLogger.cs @@ -0,0 +1,38 @@ +using Dalamud.Logging; +using MareSynchronos.MareConfiguration; +using Microsoft.Extensions.Logging; + +namespace MareSynchronos.Utils; + +internal class DalamudLogger : ILogger +{ + private readonly string _name; + private readonly MareConfigService _mareConfigService; + + public DalamudLogger(string name, MareConfigService mareConfigService) + { + this._name = name; + _mareConfigService = mareConfigService; + } + + public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) + { + if (!IsEnabled(logLevel)) return; + + if (exception == null) + PluginLog.Information($"[{_name}]{{{(int)logLevel}}} {formatter(state, exception)}"); + else if (logLevel == LogLevel.Warning) + PluginLog.Warning($"[{_name}]{{{(int)logLevel}}} {formatter(state, exception)}"); + else if (logLevel == LogLevel.Error) + PluginLog.Error($"[{_name}]{{{(int)logLevel}}} {formatter(state, exception)}"); + else + PluginLog.Fatal($"[{_name}]{{{(int)logLevel}}} {formatter(state, exception)}"); + } + + public bool IsEnabled(LogLevel logLevel) + { + return (int)_mareConfigService.Current.LogLevel <= (int)logLevel; + } + + public IDisposable BeginScope(TState state) => default!; +} diff --git a/MareSynchronos/Utils/DalamudLoggingProvider.cs b/MareSynchronos/Utils/DalamudLoggingProvider.cs index 13d85db..00ece8d 100644 --- a/MareSynchronos/Utils/DalamudLoggingProvider.cs +++ b/MareSynchronos/Utils/DalamudLoggingProvider.cs @@ -1,4 +1,5 @@ using System.Collections.Concurrent; +using MareSynchronos.MareConfiguration; using Microsoft.Extensions.Logging; namespace MareSynchronos.Utils; @@ -6,21 +7,32 @@ namespace MareSynchronos.Utils; [ProviderAlias("Dalamud")] public class DalamudLoggingProvider : ILoggerProvider { - private readonly ConcurrentDictionary _loggers = + private readonly ConcurrentDictionary _loggers = new(StringComparer.OrdinalIgnoreCase); + private readonly MareConfigService _mareConfigService; - public DalamudLoggingProvider() + public DalamudLoggingProvider(MareConfigService mareConfigService) { + _mareConfigService = mareConfigService; } public ILogger CreateLogger(string categoryName) { - return _loggers.GetOrAdd(categoryName, name => new Logger(categoryName)); + string catName = categoryName.Split(".", StringSplitOptions.RemoveEmptyEntries).Last(); + if (catName.Length > 15) + { + catName = string.Join("", catName.Take(6)) + "..." + string.Join("", catName.TakeLast(6)); + } + else + { + catName = string.Join("", Enumerable.Range(0, 15 - catName.Length).Select(_ => " ")) + catName; + } + + return _loggers.GetOrAdd(catName, name => new DalamudLogger(catName, _mareConfigService)); } public void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); _loggers.Clear(); } } diff --git a/MareSynchronos/Utils/DalamudLoggingProviderExtensions.cs b/MareSynchronos/Utils/DalamudLoggingProviderExtensions.cs new file mode 100644 index 0000000..2dd6add --- /dev/null +++ b/MareSynchronos/Utils/DalamudLoggingProviderExtensions.cs @@ -0,0 +1,17 @@ +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.DependencyInjection.Extensions; +using Microsoft.Extensions.Logging; + +namespace MareSynchronos.Utils; + +public static class DalamudLoggingProviderExtensions +{ + public static ILoggingBuilder AddDalamudLogging(this ILoggingBuilder builder) + { + builder.ClearProviders(); + + builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton()); + + return builder; + } +} \ No newline at end of file diff --git a/MareSynchronos/Utils/DalamudUtil.cs b/MareSynchronos/Utils/DalamudUtil.cs index 5aae030..ddba7f8 100644 --- a/MareSynchronos/Utils/DalamudUtil.cs +++ b/MareSynchronos/Utils/DalamudUtil.cs @@ -5,15 +5,16 @@ using Dalamud.Game.ClientState.Objects; using Dalamud.Game.ClientState.Objects.SubKinds; using FFXIVClientStructs.FFXIV.Client.Game.Character; using FFXIVClientStructs.FFXIV.Client.Game.Control; -using FFXIVClientStructs.FFXIV.Client.Graphics.Scene; using MareSynchronos.Mediator; using MareSynchronos.Models; +using Microsoft.Extensions.Logging; using GameObject = FFXIVClientStructs.FFXIV.Client.Game.Object.GameObject; namespace MareSynchronos.Utils; public class DalamudUtil : IDisposable { + private readonly ILogger _logger; private readonly ClientState _clientState; private readonly ObjectTable _objectTable; private readonly Framework _framework; @@ -39,9 +40,10 @@ public class DalamudUtil : IDisposable return false; } - public DalamudUtil(ClientState clientState, ObjectTable objectTable, Framework framework, + public DalamudUtil(ILogger logger, ClientState clientState, ObjectTable objectTable, Framework framework, Condition condition, Dalamud.Data.DataManager gameData, MareMediator mediator) { + _logger = logger; _clientState = clientState; _objectTable = objectTable; _framework = framework; @@ -66,20 +68,20 @@ public class DalamudUtil : IDisposable { if (GposeTarget != null && !IsInGpose) { - Logger.Debug("Gpose start"); + _logger.LogDebug("Gpose start"); IsInGpose = true; _mediator.Publish(new GposeStartMessage()); } else if (GposeTarget == null && IsInGpose) { - Logger.Debug("Gpose end"); + _logger.LogDebug("Gpose end"); IsInGpose = false; _mediator.Publish(new GposeEndMessage()); } if (_condition[ConditionFlag.WatchingCutscene] && !IsInCutscene) { - Logger.Debug("Cutscene start"); + _logger.LogDebug("Cutscene start"); IsInCutscene = true; _mediator.Publish(new CutsceneStartMessage()); _mediator.Publish(new HaltScanMessage("Cutscene")); @@ -87,7 +89,7 @@ public class DalamudUtil : IDisposable } else if (!_condition[ConditionFlag.WatchingCutscene] && IsInCutscene) { - Logger.Debug("Cutscene end"); + _logger.LogDebug("Cutscene end"); IsInCutscene = false; _mediator.Publish(new CutsceneEndMessage()); _mediator.Publish(new ResumeScanMessage("Cutscene")); @@ -99,7 +101,7 @@ public class DalamudUtil : IDisposable { if (!_sentBetweenAreas) { - Logger.Debug("Zone switch/Gpose start"); + _logger.LogDebug("Zone switch/Gpose start"); _sentBetweenAreas = true; _mediator.Publish(new ZoneSwitchStartMessage()); _mediator.Publish(new HaltScanMessage("Zone switch")); @@ -110,7 +112,7 @@ public class DalamudUtil : IDisposable if (_sentBetweenAreas) { - Logger.Debug("Zone switch/Gpose end"); + _logger.LogDebug("Zone switch/Gpose end"); _sentBetweenAreas = false; _mediator.Publish(new ZoneSwitchEndMessage()); _mediator.Publish(new ResumeScanMessage("Zone switch")); @@ -124,13 +126,13 @@ public class DalamudUtil : IDisposable if (localPlayer != null && !IsLoggedIn) { - Logger.Debug("Logged in"); + _logger.LogDebug("Logged in"); IsLoggedIn = true; _mediator.Publish(new DalamudLoginMessage()); } else if (localPlayer == null && IsLoggedIn) { - Logger.Debug("Logged out"); + _logger.LogDebug("Logged out"); IsLoggedIn = false; _mediator.Publish(new DalamudLogoutMessage()); } @@ -250,11 +252,11 @@ public class DalamudUtil : IDisposable return await _framework.RunOnFrameworkThread(func).ConfigureAwait(false); } - public unsafe void WaitWhileCharacterIsDrawing(GameObjectHandler handler, int timeOut = 5000, CancellationToken? ct = null) + public unsafe void WaitWhileCharacterIsDrawing(ILogger logger, GameObjectHandler handler, Guid redrawId, int timeOut = 5000, CancellationToken? ct = null) { if (!_clientState.IsLoggedIn || handler.Address == IntPtr.Zero) return; - Logger.Verbose($"Starting wait for {handler} to draw"); + logger.LogTrace($"[{redrawId}] Starting wait for {handler} to draw"); const int tick = 250; int curWaitTime = 0; @@ -265,18 +267,20 @@ public class DalamudUtil : IDisposable && curWaitTime < timeOut && handler.IsBeingDrawn) // 0b100000000000 is "still rendering" or something { - Logger.Verbose($"Waiting for {handler} to finish drawing"); + logger.LogTrace($"[{redrawId}] Waiting for {handler} to finish drawing"); curWaitTime += tick; Thread.Sleep(tick); } + + logger.LogTrace($"[{redrawId}] Finished drawing after {curWaitTime}ms"); } catch (NullReferenceException ex) { - Logger.Warn("Error accessing " + handler + ", object does not exist anymore?", ex); + logger.LogWarning("Error accessing " + handler + ", object does not exist anymore?", ex); } catch (AccessViolationException ex) { - Logger.Warn("Error accessing " + handler + ", object does not exist anymore?", ex); + logger.LogWarning("Error accessing " + handler + ", object does not exist anymore?", ex); } } @@ -286,11 +290,11 @@ public class DalamudUtil : IDisposable var obj = (GameObject*)characterAddress; const int tick = 250; int curWaitTime = 0; - Logger.Verbose("RenderFlags:" + obj->RenderFlags.ToString("X")); + _logger.LogTrace("RenderFlags:" + obj->RenderFlags.ToString("X")); // ReSharper disable once LoopVariableIsNeverChangedInsideLoop while (obj->RenderFlags != 0x00 && curWaitTime < timeOut) { - Logger.Verbose($"Waiting for gpose actor to finish drawing"); + _logger.LogTrace($"Waiting for gpose actor to finish drawing"); curWaitTime += tick; Thread.Sleep(tick); } @@ -300,7 +304,7 @@ public class DalamudUtil : IDisposable public void Dispose() { - Logger.Verbose($"Disposing {GetType()}"); + _logger.LogTrace($"Disposing {GetType()}"); _framework.Update -= FrameworkOnUpdate; } } diff --git a/MareSynchronos/Utils/Logger.cs b/MareSynchronos/Utils/Logger.cs deleted file mode 100644 index 47fd25c..0000000 --- a/MareSynchronos/Utils/Logger.cs +++ /dev/null @@ -1,106 +0,0 @@ -using System.Diagnostics; -using Dalamud.Logging; -using Dalamud.Utility; -using Microsoft.Extensions.Logging; - -namespace MareSynchronos.Utils; - -internal class Logger : ILogger -{ - private readonly string _name; - - public static void Info(string? info) - { - var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; - PluginLog.Information($"[{caller}] {info}"); - } - - public static void Debug(string? debug, string stringToHighlight = "") - { - var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; - if (debug != null && debug.Contains(stringToHighlight, StringComparison.Ordinal) && !stringToHighlight.IsNullOrEmpty()) - { - PluginLog.Warning($"[{caller}] {debug}"); - } - else - { - PluginLog.Debug($"[{caller}] {debug}"); - } - } - - public static void Error(string? msg, Exception ex) - { - var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; - PluginLog.Error($"[{caller}] {msg} {Environment.NewLine} Exception: {ex?.ToString()}"); - } - - public static void Warn(string? msg, Exception ex) - { - var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; - PluginLog.Warning($"[{caller}] {msg} {Environment.NewLine} Exception: {ex?.ToString()}"); - } - - public static void Error(string? msg) - { - var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; - PluginLog.Error($"[{caller}] {msg}"); - } - - public static void Warn(string? warn) - { - var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; - PluginLog.Warning($"[{caller}] {warn}"); - } - - public static void Verbose(string? verbose) - { - var caller = new StackTrace().GetFrame(1)?.GetMethod()?.ReflectedType?.Name ?? "Unknown"; -#if DEBUG - PluginLog.Debug($"[{caller}] {verbose}"); -#else - PluginLog.Verbose($"[{caller}] {verbose}"); -#endif - } - - public Logger(string name) - { - this._name = name; - } - - public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) - { - if (!IsEnabled(logLevel)) return; - - switch (logLevel) - { - case LogLevel.Debug: - Debug($"[{_name}] [{eventId}] {formatter(state, exception)}"); - break; - case LogLevel.Error: - case LogLevel.Critical: - Error($"[{_name}] [{eventId}] {formatter(state, exception)}", exception); - break; - case LogLevel.Information: - Info($"[{_name}] [{eventId}] {formatter(state, exception)}"); - break; - case LogLevel.Warning: - Warn($"[{_name}] [{eventId}] {formatter(state, exception)}", exception); - break; - case LogLevel.Trace: - default: -#if DEBUG - PluginLog.Verbose($"[{_name}] [{eventId}] {formatter(state, exception)}"); -#else - PluginLog.Verbose($"[{_name}] {eventId} {state} {formatter(state, exception)}"); -#endif - break; - } - } - - public bool IsEnabled(LogLevel logLevel) - { - return true; - } - - public IDisposable BeginScope(TState state) => default!; -} diff --git a/MareSynchronos/WebAPI/ApIController.Functions.Files.cs b/MareSynchronos/WebAPI/ApIController.Functions.Files.cs index d2975c4..b310857 100644 --- a/MareSynchronos/WebAPI/ApIController.Functions.Files.cs +++ b/MareSynchronos/WebAPI/ApIController.Functions.Files.cs @@ -11,9 +11,9 @@ using MareSynchronos.API.Dto.Files; using MareSynchronos.API.Routes; using MareSynchronos.Mediator; using MareSynchronos.UI; -using MareSynchronos.Utils; using MareSynchronos.WebAPI.Utils; using Microsoft.AspNetCore.SignalR.Client; +using Microsoft.Extensions.Logging; namespace MareSynchronos.WebAPI; @@ -28,7 +28,7 @@ public partial class ApiController { if (CurrentUploads.Any()) { - Logger.Debug("Cancelling current upload"); + _logger.LogDebug("Cancelling current upload"); _uploadCancellationTokenSource?.Cancel(); _uploadCancellationTokenSource?.Dispose(); _uploadCancellationTokenSource = null; @@ -102,7 +102,7 @@ public partial class ApiController localTimeoutCts.Dispose(); composite.Dispose(); - Logger.Debug($"Download {requestId} ready"); + _logger.LogDebug($"Download {requestId} ready"); } catch (TaskCanceledException) { @@ -133,14 +133,14 @@ public partial class ApiController { var requestId = await GetQueueRequest(fileTransfer, ct).ConfigureAwait(false); - Logger.Debug($"GUID {requestId} for file {fileTransfer.Hash} on server {fileTransfer.DownloadUri}"); + _logger.LogDebug($"GUID {requestId} for file {fileTransfer.Hash} on server {fileTransfer.DownloadUri}"); await WaitForDownloadReady(fileTransfer, requestId, ct).ConfigureAwait(false); HttpResponseMessage response = null!; var requestUrl = MareFiles.CacheGetFullPath(fileTransfer.DownloadUri, requestId); - Logger.Debug($"Downloading {requestUrl} for file {fileTransfer.Hash}"); + _logger.LogDebug($"Downloading {requestUrl} for file {fileTransfer.Hash}"); try { response = await SendRequestAsync(HttpMethod.Get, requestUrl, ct).ConfigureAwait(false); @@ -148,7 +148,7 @@ public partial class ApiController } catch (HttpRequestException ex) { - Logger.Warn($"Error during download of {requestUrl}, HttpStatusCode: {ex.StatusCode}"); + _logger.LogWarning($"Error during download of {requestUrl}, HttpStatusCode: {ex.StatusCode}"); if (ex.StatusCode is HttpStatusCode.NotFound or HttpStatusCode.Unauthorized) { throw new Exception($"Http error {ex.StatusCode} (cancelled: {ct.IsCancellationRequested}): {requestUrl}", ex); @@ -173,12 +173,12 @@ public partial class ApiController progress.Report(bytesRead); } - Logger.Debug($"{requestUrl} downloaded to {tempPath}"); + _logger.LogDebug($"{requestUrl} downloaded to {tempPath}"); } } catch (Exception ex) { - Logger.Warn($"Error during file download of {requestUrl}", ex); + _logger.LogWarning($"Error during file download of {requestUrl}", ex); try { if (!tempPath.IsNullOrEmpty()) @@ -220,11 +220,11 @@ public partial class ApiController if (requestMessage.Content != null) { - Logger.Debug("Sending " + requestMessage.Method + " to " + requestMessage.RequestUri + " (Content: " + await (((JsonContent)requestMessage.Content).ReadAsStringAsync()) + ")"); + _logger.LogDebug("Sending " + requestMessage.Method + " to " + requestMessage.RequestUri + " (Content: " + await (((JsonContent)requestMessage.Content).ReadAsStringAsync()) + ")"); } else { - Logger.Debug("Sending " + requestMessage.Method + " to " + requestMessage.RequestUri); + _logger.LogDebug("Sending " + requestMessage.Method + " to " + requestMessage.RequestUri); } try @@ -235,7 +235,7 @@ public partial class ApiController } catch (Exception ex) { - Logger.Error("Error during SendRequestInternal for " + requestMessage.RequestUri, ex); + _logger.LogCritical("Error during SendRequestInternal for " + requestMessage.RequestUri, ex); throw; } } @@ -249,12 +249,12 @@ public partial class ApiController private async Task DownloadFilesInternal(int currentDownloadId, List fileReplacement, CancellationToken ct) { - Logger.Debug("Downloading files (Download ID " + currentDownloadId + ")"); + _logger.LogDebug("Downloading files (Download ID " + currentDownloadId + ")"); List downloadFileInfoFromService = new(); downloadFileInfoFromService.AddRange(await FilesGetSizes(fileReplacement.Select(f => f.Hash).ToList()).ConfigureAwait(false)); - Logger.Debug("Files with size 0 or less: " + string.Join(", ", downloadFileInfoFromService.Where(f => f.Size <= 0).Select(f => f.Hash))); + _logger.LogDebug("Files with size 0 or less: " + string.Join(", ", downloadFileInfoFromService.Where(f => f.Size <= 0).Select(f => f.Hash))); CurrentDownloads[currentDownloadId] = downloadFileInfoFromService.Distinct().Select(d => new DownloadFileTransfer(d)) .Where(d => d.CanBeTransferred).ToList(); @@ -296,13 +296,13 @@ public partial class ApiController catch (OperationCanceledException) { File.Delete(tempPath); - Logger.Debug("Detected cancellation, removing " + currentDownloadId); + _logger.LogDebug("Detected cancellation, removing " + currentDownloadId); CancelDownload(currentDownloadId); return; } catch (Exception ex) { - Logger.Error("Error during download of " + file.Hash, ex); + _logger.LogCritical("Error during download of " + file.Hash, ex); return; } @@ -329,14 +329,14 @@ public partial class ApiController } catch (Exception ex) { - Logger.Warn("Issue adding file to the DB"); - Logger.Warn(ex.Message); - Logger.Warn(ex.StackTrace); + _logger.LogWarning("Issue adding file to the DB"); + _logger.LogWarning(ex.Message); + _logger.LogWarning(ex.StackTrace); } } }).ConfigureAwait(false); - Logger.Debug("Download complete, removing " + currentDownloadId); + _logger.LogDebug("Download complete, removing " + currentDownloadId); CancelDownload(currentDownloadId); } @@ -350,23 +350,23 @@ public partial class ApiController _uploadCancellationTokenSource = new CancellationTokenSource(); var uploadToken = _uploadCancellationTokenSource.Token; - Logger.Debug($"Sending Character data {data.DataHash.Value} to service {_serverManager.CurrentApiUrl}"); + _logger.LogDebug($"Sending Character data {data.DataHash.Value} to service {_serverManager.CurrentApiUrl}"); HashSet unverifiedUploads = VerifyFiles(data); if (unverifiedUploads.Any()) { await UploadMissingFiles(unverifiedUploads, uploadToken).ConfigureAwait(false); - Logger.Info("Upload complete for " + data.DataHash.Value); + _logger.LogInformation("Upload complete for " + data.DataHash.Value); } await PushCharacterDataInternal(data, visibleCharacters.ToList()).ConfigureAwait(false); } catch (OperationCanceledException) { - Logger.Debug("Upload operation was cancelled"); + _logger.LogDebug("Upload operation was cancelled"); } catch (Exception ex) { - Logger.Warn("Error during upload of files", ex); + _logger.LogWarning("Error during upload of files", ex); } finally { @@ -387,7 +387,7 @@ public partial class ApiController if (verifiedTime < DateTime.UtcNow.Subtract(TimeSpan.FromMinutes(10))) { - Logger.Verbose("Verifying " + item + ", last verified: " + verifiedTime); + _logger.LogTrace("Verifying " + item + ", last verified: " + verifiedTime); unverifiedUploadHashes.Add(item); } } @@ -399,7 +399,7 @@ public partial class ApiController { unverifiedUploadHashes = unverifiedUploadHashes.Where(h => _fileDbManager.GetFileCacheByHash(h) != null).ToHashSet(StringComparer.Ordinal); - Logger.Debug("Verifying " + unverifiedUploadHashes.Count + " files"); + _logger.LogDebug("Verifying " + unverifiedUploadHashes.Count + " files"); var filesToUpload = await FilesSend(unverifiedUploadHashes.ToList()).ConfigureAwait(false); foreach (var file in filesToUpload.Where(f => !f.IsForbidden)) @@ -413,7 +413,7 @@ public partial class ApiController } catch (Exception ex) { - Logger.Warn("Tried to request file " + file.Hash + " but file was not present", ex); + _logger.LogWarning("Tried to request file " + file.Hash + " but file was not present", ex); } } @@ -431,10 +431,10 @@ public partial class ApiController } var totalSize = CurrentUploads.Sum(c => c.Total); - Logger.Debug("Compressing and uploading files"); + _logger.LogDebug("Compressing and uploading files"); foreach (var file in CurrentUploads.Where(f => f.CanBeTransferred && !f.IsTransferred).ToList()) { - Logger.Debug("Compressing and uploading " + file); + _logger.LogDebug("Compressing and uploading " + file); var data = await GetCompressedFileData(file.Hash, uploadToken).ConfigureAwait(false); CurrentUploads.Single(e => string.Equals(e.Hash, data.Item1, StringComparison.Ordinal)).Total = data.Item2.Length; await UploadFile(data.Item2, file.Hash, uploadToken).ConfigureAwait(false); @@ -445,15 +445,15 @@ public partial class ApiController if (CurrentUploads.Any()) { var compressedSize = CurrentUploads.Sum(c => c.Total); - Logger.Debug($"Compressed {UiShared.ByteToString(totalSize)} to {UiShared.ByteToString(compressedSize)} ({(compressedSize / (double)totalSize):P2})"); + _logger.LogDebug($"Compressed {UiShared.ByteToString(totalSize)} to {UiShared.ByteToString(compressedSize)} ({(compressedSize / (double)totalSize):P2})"); - Logger.Debug("Upload tasks complete, waiting for server to confirm"); - Logger.Debug("Uploads open: " + CurrentUploads.Any(c => c.IsInTransfer)); + _logger.LogDebug("Upload tasks complete, waiting for server to confirm"); + _logger.LogDebug("Uploads open: " + CurrentUploads.Any(c => c.IsInTransfer)); const double waitStep = 1.0d; while (CurrentUploads.Any(c => c.IsInTransfer) && !uploadToken.IsCancellationRequested) { await Task.Delay(TimeSpan.FromSeconds(waitStep), uploadToken).ConfigureAwait(false); - Logger.Debug("Waiting for uploads to finish"); + _logger.LogDebug("Waiting for uploads to finish"); } } @@ -467,7 +467,7 @@ public partial class ApiController private async Task PushCharacterDataInternal(CharacterData character, List visibleCharacters) { - Logger.Info("Pushing character data for " + character.DataHash.Value + " to " + string.Join(", ", visibleCharacters.Select(c => c.AliasOrUID))); + _logger.LogInformation("Pushing character data for " + character.DataHash.Value + " to " + string.Join(", ", visibleCharacters.Select(c => c.AliasOrUID))); StringBuilder sb = new(); foreach (var item in character.FileReplacements) { @@ -477,7 +477,7 @@ public partial class ApiController { sb.AppendLine($"GlamourerData for {item.Key}: {!string.IsNullOrEmpty(item.Value)}"); } - Logger.Debug("Chara data contained: " + Environment.NewLine + sb.ToString()); + _logger.LogDebug("Chara data contained: " + Environment.NewLine + sb.ToString()); await UserPushData(new(visibleCharacters, character)).ConfigureAwait(false); } diff --git a/MareSynchronos/WebAPI/ApIController.Functions.Users.cs b/MareSynchronos/WebAPI/ApIController.Functions.Users.cs index 2abae86..05f5b4a 100644 --- a/MareSynchronos/WebAPI/ApIController.Functions.Users.cs +++ b/MareSynchronos/WebAPI/ApIController.Functions.Users.cs @@ -1,6 +1,6 @@ using MareSynchronos.API.Dto.User; -using MareSynchronos.Utils; using Microsoft.AspNetCore.SignalR.Client; +using Microsoft.Extensions.Logging; namespace MareSynchronos.WebAPI; @@ -22,7 +22,7 @@ public partial class ApiController } catch (Exception ex) { - Logger.Warn("Failed to Push character data: " + ex.Message); + _logger.LogWarning("Failed to Push character data: " + ex.Message); } } @@ -38,7 +38,6 @@ public partial class ApiController public async Task UserSetPairPermissions(UserPermissionsDto dto) { - Logger.Verbose("Sending UserSetPairPermissions: " + dto); await _mareHub!.SendAsync(nameof(UserSetPairPermissions), dto).ConfigureAwait(false); } diff --git a/MareSynchronos/WebAPI/ApiController.Functions.Callbacks.cs b/MareSynchronos/WebAPI/ApiController.Functions.Callbacks.cs index b9c6ca2..14da331 100644 --- a/MareSynchronos/WebAPI/ApiController.Functions.Callbacks.cs +++ b/MareSynchronos/WebAPI/ApiController.Functions.Callbacks.cs @@ -4,8 +4,8 @@ using MareSynchronos.API.Dto; using MareSynchronos.API.Dto.Group; using MareSynchronos.API.Dto.User; using MareSynchronos.Mediator; -using MareSynchronos.Utils; using Microsoft.AspNetCore.SignalR.Client; +using Microsoft.Extensions.Logging; namespace MareSynchronos.WebAPI; @@ -19,7 +19,7 @@ public partial class ApiController } catch (Exception ex) { - Logger.Error("Error on executing safely", ex); + _logger.LogCritical("Error on executing safely", ex); } } @@ -55,7 +55,7 @@ public partial class ApiController public Task Client_GroupSendFullInfo(GroupFullInfoDto dto) { - Logger.Verbose("Client_GroupSendFullInfo: " + dto); + _logger.LogTrace("Client_GroupSendFullInfo: " + dto); ExecuteSafely(() => _pairManager.AddGroup(dto)); return Task.CompletedTask; } @@ -68,7 +68,7 @@ public partial class ApiController public Task Client_GroupSendInfo(GroupInfoDto dto) { - Logger.Verbose("Client_GroupSendInfo: " + dto); + _logger.LogTrace("Client_GroupSendInfo: " + dto); ExecuteSafely(() => _pairManager.SetGroupInfo(dto)); return Task.CompletedTask; } @@ -81,7 +81,7 @@ public partial class ApiController public Task Client_GroupDelete(GroupDto dto) { - Logger.Verbose("Client_GroupDelete: " + dto); + _logger.LogTrace("Client_GroupDelete: " + dto); ExecuteSafely(() => _pairManager.RemoveGroup(dto.Group)); return Task.CompletedTask; } @@ -94,7 +94,7 @@ public partial class ApiController public Task Client_GroupPairJoined(GroupPairFullInfoDto dto) { - Logger.Verbose("Client_GroupPairJoined: " + dto); + _logger.LogTrace("Client_GroupPairJoined: " + dto); ExecuteSafely(() => _pairManager.AddGroupPair(dto)); return Task.CompletedTask; } @@ -107,7 +107,7 @@ public partial class ApiController public Task Client_GroupPairLeft(GroupPairDto dto) { - Logger.Verbose("Client_GroupPairLeft: " + dto); + _logger.LogTrace("Client_GroupPairLeft: " + dto); ExecuteSafely(() => _pairManager.RemoveGroupPair(dto)); return Task.CompletedTask; } @@ -120,7 +120,7 @@ public partial class ApiController public Task Client_GroupChangePermissions(GroupPermissionDto dto) { - Logger.Verbose("Client_GroupChangePermissions: " + dto); + _logger.LogTrace("Client_GroupChangePermissions: " + dto); ExecuteSafely(() => _pairManager.SetGroupPermissions(dto)); return Task.CompletedTask; } @@ -133,7 +133,7 @@ public partial class ApiController public Task Client_GroupPairChangePermissions(GroupPairUserPermissionDto dto) { - Logger.Verbose("Client_GroupPairChangePermissions: " + dto); + _logger.LogTrace("Client_GroupPairChangePermissions: " + dto); ExecuteSafely(() => { if (string.Equals(dto.UID, UID, StringComparison.Ordinal)) _pairManager.SetGroupUserPermissions(dto); @@ -150,7 +150,7 @@ public partial class ApiController public Task Client_GroupPairChangeUserInfo(GroupPairUserInfoDto dto) { - Logger.Verbose("Client_GroupPairChangeUserInfo: " + dto); + _logger.LogTrace("Client_GroupPairChangeUserInfo: " + dto); ExecuteSafely(() => { if (string.Equals(dto.UID, UID, StringComparison.Ordinal)) _pairManager.SetGroupStatusInfo(dto); @@ -161,7 +161,7 @@ public partial class ApiController public Task Client_UserReceiveCharacterData(OnlineUserCharaDataDto dto) { - Logger.Verbose("Client_UserReceiveCharacterData: " + dto.User); + _logger.LogTrace("Client_UserReceiveCharacterData: " + dto.User); ExecuteSafely(() => _pairManager.ReceiveCharaData(dto)); return Task.CompletedTask; } @@ -174,7 +174,7 @@ public partial class ApiController public Task Client_UserAddClientPair(UserPairDto dto) { - Logger.Debug($"Client_UserAddClientPair: " + dto); + _logger.LogDebug($"Client_UserAddClientPair: " + dto); ExecuteSafely(() => _pairManager.AddUserPair(dto)); return Task.CompletedTask; } @@ -187,7 +187,7 @@ public partial class ApiController public Task Client_UserRemoveClientPair(UserDto dto) { - Logger.Debug($"Client_UserRemoveClientPair: " + dto); + _logger.LogDebug($"Client_UserRemoveClientPair: " + dto); ExecuteSafely(() => _pairManager.RemoveUserPair(dto)); return Task.CompletedTask; } @@ -200,7 +200,7 @@ public partial class ApiController public Task Client_UserSendOffline(UserDto dto) { - Logger.Debug($"Client_UserSendOffline: {dto}"); + _logger.LogDebug($"Client_UserSendOffline: {dto}"); ExecuteSafely(() => _pairManager.MarkPairOffline(dto.User)); return Task.CompletedTask; } @@ -213,7 +213,7 @@ public partial class ApiController public Task Client_UserSendOnline(OnlineUserIdentDto dto) { - Logger.Debug($"Client_UserSendOnline: {dto}"); + _logger.LogDebug($"Client_UserSendOnline: {dto}"); ExecuteSafely(() => _pairManager.MarkPairOnline(dto, this)); return Task.CompletedTask; } @@ -226,7 +226,7 @@ public partial class ApiController public Task Client_UserUpdateOtherPairPermissions(UserPermissionsDto dto) { - Logger.Debug($"Client_UserUpdateOtherPairPermissions: {dto}"); + _logger.LogDebug($"Client_UserUpdateOtherPairPermissions: {dto}"); ExecuteSafely(() => _pairManager.UpdatePairPermissions(dto)); return Task.CompletedTask; } @@ -239,7 +239,7 @@ public partial class ApiController public Task Client_UserUpdateSelfPairPermissions(UserPermissionsDto dto) { - Logger.Debug($"Client_UserUpdateSelfPairPermissions: {dto}"); + _logger.LogDebug($"Client_UserUpdateSelfPairPermissions: {dto}"); ExecuteSafely(() => _pairManager.UpdateSelfPairPermissions(dto)); return Task.CompletedTask; } @@ -275,7 +275,7 @@ public partial class ApiController public Task Client_DownloadReady(Guid requestId) { - Logger.Debug($"Server sent {requestId} ready"); + _logger.LogDebug($"Server sent {requestId} ready"); _downloadReady[requestId] = true; return Task.CompletedTask; } diff --git a/MareSynchronos/WebAPI/ApiController.Functions.Groups.cs b/MareSynchronos/WebAPI/ApiController.Functions.Groups.cs index 1461b65..d10e17c 100644 --- a/MareSynchronos/WebAPI/ApiController.Functions.Groups.cs +++ b/MareSynchronos/WebAPI/ApiController.Functions.Groups.cs @@ -1,5 +1,4 @@ using MareSynchronos.API.Dto.Group; -using MareSynchronos.Utils; using Microsoft.AspNetCore.SignalR.Client; namespace MareSynchronos.WebAPI; @@ -67,7 +66,6 @@ public partial class ApiController public async Task GroupChangeIndividualPermissionState(GroupPairUserPermissionDto dto) { CheckConnection(); - Logger.Debug("Sending " + dto); await _mareHub!.SendAsync(nameof(GroupChangeIndividualPermissionState), dto).ConfigureAwait(false); } diff --git a/MareSynchronos/WebAPI/ApiController.cs b/MareSynchronos/WebAPI/ApiController.cs index 5a478a0..69c243e 100644 --- a/MareSynchronos/WebAPI/ApiController.cs +++ b/MareSynchronos/WebAPI/ApiController.cs @@ -48,10 +48,10 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH private HttpClient _httpClient; - public ApiController(MareConfigService configService, DalamudUtil dalamudUtil, FileCacheManager fileDbManager, - PairManager pairManager, ServerConfigurationManager serverManager, MareMediator mediator) : base(mediator) + public ApiController(ILogger logger, MareConfigService configService, DalamudUtil dalamudUtil, FileCacheManager fileDbManager, + PairManager pairManager, ServerConfigurationManager serverManager, MareMediator mediator) : base(logger, mediator) { - Logger.Verbose("Creating " + nameof(ApiController)); + _logger.LogTrace("Creating " + nameof(ApiController)); _configService = configService; _dalamudUtil = dalamudUtil; @@ -107,21 +107,21 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH get => _serverState; private set { - Logger.Debug($"New ServerState: {value}, prev ServerState: {_serverState}"); + _logger.LogDebug($"New ServerState: {value}, prev ServerState: {_serverState}"); _serverState = value; } } public async Task CreateConnections(bool forceGetToken = false) { - Logger.Debug("CreateConnections called"); + _logger.LogDebug("CreateConnections called"); _httpClient?.Dispose(); _httpClient = new(); if (_serverManager.CurrentServer?.FullPause ?? true) { - Logger.Info("Not recreating Connection, paused"); + _logger.LogInformation("Not recreating Connection, paused"); _connectionDto = null; await StopConnection(_connectionCancellationTokenSource.Token, ServerState.Disconnected).ConfigureAwait(false); _connectionCancellationTokenSource.Cancel(); @@ -131,7 +131,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH var secretKey = _serverManager.GetSecretKey(); if (secretKey.IsNullOrEmpty()) { - Logger.Warn("No secret key set for current character"); + _logger.LogWarning("No secret key set for current character"); _connectionDto = null; await StopConnection(_connectionCancellationTokenSource.Token, ServerState.NoSecretKey).ConfigureAwait(false); _connectionCancellationTokenSource.Cancel(); @@ -140,7 +140,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH await StopConnection(_connectionCancellationTokenSource.Token, ServerState.Disconnected).ConfigureAwait(false); - Logger.Info("Recreating Connection"); + _logger.LogInformation("Recreating Connection"); _connectionCancellationTokenSource.Cancel(); _connectionCancellationTokenSource = new CancellationTokenSource(); @@ -155,11 +155,11 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH try { - Logger.Debug("Building connection"); + _logger.LogDebug("Building connection"); if (_serverManager.GetToken() == null || forceGetToken) { - Logger.Debug("Requesting new JWT"); + _logger.LogDebug("Requesting new JWT"); using HttpClient httpClient = new(); var postUri = MareAuth.AuthFullPath(new Uri(_serverManager.CurrentApiUrl .Replace("wss://", "https://", StringComparison.OrdinalIgnoreCase) @@ -173,12 +173,12 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH AuthFailureMessage = await result.Content.ReadAsStringAsync().ConfigureAwait(false); result.EnsureSuccessStatusCode(); _serverManager.SaveToken(await result.Content.ReadAsStringAsync().ConfigureAwait(false)); - Logger.Debug("JWT Success"); + _logger.LogDebug("JWT Success"); } while (!_dalamudUtil.IsPlayerPresent && !token.IsCancellationRequested) { - Logger.Debug("Player not loaded in yet, waiting"); + _logger.LogDebug("Player not loaded in yet, waiting"); await Task.Delay(TimeSpan.FromSeconds(1), token).ConfigureAwait(false); } @@ -209,7 +209,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH } catch (HttpRequestException ex) { - Logger.Warn("HttpRequestException on Connection", ex); + _logger.LogWarning("HttpRequestException on Connection", ex); if (ex.StatusCode == System.Net.HttpStatusCode.Unauthorized) { @@ -219,15 +219,15 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH else { ServerState = ServerState.Reconnecting; - Logger.Info("Failed to establish connection, retrying"); + _logger.LogInformation("Failed to establish connection, retrying"); await Task.Delay(TimeSpan.FromSeconds(new Random().Next(5, 20)), token).ConfigureAwait(false); } } catch (Exception ex) { - Logger.Warn("Exception on Connection", ex); + _logger.LogWarning("Exception on Connection", ex); - Logger.Info("Failed to establish connection, retrying"); + _logger.LogInformation("Failed to establish connection, retrying"); await Task.Delay(TimeSpan.FromSeconds(new Random().Next(5, 20)), token).ConfigureAwait(false); } } @@ -239,7 +239,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH { await Task.Delay(TimeSpan.FromSeconds(30), ct).ConfigureAwait(false); var needsRestart = await CheckClientHealth().ConfigureAwait(false); - Logger.Debug("Checked Client Health State"); + _logger.LogDebug("Checked Client Health State"); } } @@ -247,7 +247,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH { if (_mareHub == null) return; - Logger.Debug("Initializing data"); + _logger.LogDebug("Initializing data"); OnDownloadReady((guid) => Client_DownloadReady(guid)); OnReceiveServerMessage((sev, msg) => Client_ReceiveServerMessage(sev, msg)); OnUpdateSystemInfo((dto) => Client_UpdateSystemInfo(dto)); @@ -271,12 +271,12 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH foreach (var userPair in await UserGetPairedClients().ConfigureAwait(false)) { - Logger.Debug($"Pair: {userPair}"); + _logger.LogDebug($"Pair: {userPair}"); _pairManager.AddUserPair(userPair, addToLastAddedUser: false); } foreach (var entry in await GroupsGetAll().ConfigureAwait(false)) { - Logger.Debug($"Group: {entry}"); + _logger.LogDebug($"Group: {entry}"); _pairManager.AddGroup(entry); } foreach (var group in _pairManager.GroupPairs.Keys) @@ -284,7 +284,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH var users = await GroupsGetUsersInGroup(group).ConfigureAwait(false); foreach (var user in users) { - Logger.Debug($"GroupPair: {user}"); + _logger.LogDebug($"GroupPair: {user}"); _pairManager.AddGroupPair(user); } } @@ -342,7 +342,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH .WithAutomaticReconnect(new ForeverRetryPolicy(Mediator)) .ConfigureLogging(a => { - a.ClearProviders().AddProvider(new DalamudLoggingProvider()); + a.ClearProviders().AddProvider(new DalamudLoggingProvider(_configService)); a.SetMinimumLevel(LogLevel.Information); }) .Build(); @@ -357,7 +357,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH Mediator.Publish(new DisconnectedMessage()); _pairManager.ClearPairs(); ServerState = ServerState.Offline; - Logger.Info("Connection closed"); + _logger.LogInformation("Connection closed"); return Task.CompletedTask; } @@ -367,7 +367,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH _healthCheckTokenSource?.Cancel(); ServerState = ServerState.Reconnecting; Mediator.Publish(new NotificationMessage("Connection lost", "Connection lost to " + _serverManager.CurrentServer!.ServerName, NotificationType.Warning, 5000)); - Logger.Warn("Connection closed... Reconnecting", arg); + _logger.LogWarning("Connection closed... Reconnecting", arg); return Task.CompletedTask; } @@ -394,7 +394,7 @@ public partial class ApiController : MediatorSubscriberBase, IDisposable, IMareH _initialized = false; _healthCheckTokenSource?.Cancel(); _uploadCancellationTokenSource?.Cancel(); - Logger.Info("Stopping existing connection"); + _logger.LogInformation("Stopping existing connection"); _mareHub.Closed -= MareHubOnClosed; _mareHub.Reconnecting -= MareHubOnReconnecting; _mareHub.Reconnected -= MareHubOnReconnected;