diff --git a/LightlessSync/PlayerData/Factories/PlayerDataFactory.cs b/LightlessSync/PlayerData/Factories/PlayerDataFactory.cs index aeb04f3..371a2a9 100644 --- a/LightlessSync/PlayerData/Factories/PlayerDataFactory.cs +++ b/LightlessSync/PlayerData/Factories/PlayerDataFactory.cs @@ -8,6 +8,8 @@ using LightlessSync.PlayerData.Handlers; using LightlessSync.Services; using LightlessSync.Services.Mediator; using Microsoft.Extensions.Logging; +using System.Collections.Concurrent; +using System.Diagnostics; namespace LightlessSync.PlayerData.Factories; @@ -23,9 +25,27 @@ public class PlayerDataFactory private readonly TransientResourceManager _transientResourceManager; private static readonly SemaphoreSlim _papParseLimiter = new(1, 1); - public PlayerDataFactory(ILogger logger, DalamudUtilService dalamudUtil, IpcManager ipcManager, - TransientResourceManager transientResourceManager, FileCacheManager fileReplacementFactory, - PerformanceCollectorService performanceCollector, XivDataAnalyzer modelAnalyzer, LightlessMediator lightlessMediator) + // Transient resolved entries threshold + private const int _maxTransientResolvedEntries = 1000; + + // Character build caches + private readonly ConcurrentDictionary> _characterBuildInflight = new(); + private readonly ConcurrentDictionary _characterBuildCache = new(); + + // Time out thresholds + private static readonly TimeSpan _characterCacheTtl = TimeSpan.FromMilliseconds(750); + private static readonly TimeSpan _softReturnIfBusyAfter = TimeSpan.FromMilliseconds(250); + private static readonly TimeSpan _hardBuildTimeout = TimeSpan.FromSeconds(30); + + public PlayerDataFactory( + ILogger logger, + DalamudUtilService dalamudUtil, + IpcManager ipcManager, + TransientResourceManager transientResourceManager, + FileCacheManager fileReplacementFactory, + PerformanceCollectorService performanceCollector, + XivDataAnalyzer modelAnalyzer, + LightlessMediator lightlessMediator) { _logger = logger; _dalamudUtil = dalamudUtil; @@ -37,13 +57,12 @@ public class PlayerDataFactory _lightlessMediator = lightlessMediator; _logger.LogTrace("Creating {this}", nameof(PlayerDataFactory)); } + private sealed record CacheEntry(CharacterDataFragment Fragment, DateTime CreatedUtc); public async Task BuildCharacterData(GameObjectHandler playerRelatedObject, CancellationToken token) { if (!_ipcManager.Initialized) - { throw new InvalidOperationException("Penumbra or Glamourer is not connected"); - } if (playerRelatedObject == null) return null; @@ -68,16 +87,17 @@ public class PlayerDataFactory if (pointerIsZero) { - _logger.LogTrace("Pointer was zero for {objectKind}", playerRelatedObject.ObjectKind); + _logger.LogTrace("Pointer was zero for {objectKind}; couldn't build character", playerRelatedObject.ObjectKind); return null; } try { - return await _performanceCollector.LogPerformance(this, $"CreateCharacterData>{playerRelatedObject.ObjectKind}", async () => - { - return await CreateCharacterData(playerRelatedObject, token).ConfigureAwait(false); - }).ConfigureAwait(true); + return await _performanceCollector.LogPerformance( + this, + $"CreateCharacterData>{playerRelatedObject.ObjectKind}", + async () => await CreateCharacterData(playerRelatedObject, token).ConfigureAwait(false) + ).ConfigureAwait(false); } catch (OperationCanceledException) { @@ -93,17 +113,14 @@ public class PlayerDataFactory } private async Task CheckForNullDrawObject(IntPtr playerPointer) - { - return await _dalamudUtil.RunOnFrameworkThread(() => CheckForNullDrawObjectUnsafe(playerPointer)).ConfigureAwait(false); - } + => await _dalamudUtil.RunOnFrameworkThread(() => CheckForNullDrawObjectUnsafe(playerPointer)).ConfigureAwait(false); - private unsafe bool CheckForNullDrawObjectUnsafe(IntPtr playerPointer) + private unsafe static bool CheckForNullDrawObjectUnsafe(IntPtr playerPointer) { if (playerPointer == IntPtr.Zero) return true; var character = (Character*)playerPointer; - if (character == null) return true; @@ -114,111 +131,167 @@ public class PlayerDataFactory return gameObject->DrawObject == null; } - private async Task CreateCharacterData(GameObjectHandler playerRelatedObject, CancellationToken ct) + private static bool IsCacheFresh(CacheEntry entry) + => (DateTime.UtcNow - entry.CreatedUtc) <= _characterCacheTtl; + + private Task CreateCharacterData(GameObjectHandler playerRelatedObject, CancellationToken ct) + => CreateCharacterDataCoalesced(playerRelatedObject, ct); + + private async Task CreateCharacterDataCoalesced(GameObjectHandler obj, CancellationToken ct) + { + var key = obj.Address; + + if (_characterBuildCache.TryGetValue(key, out var cached) && IsCacheFresh(cached) && !_characterBuildInflight.ContainsKey(key)) + return cached.Fragment; + + var buildTask = _characterBuildInflight.GetOrAdd(key, _ => BuildAndCacheAsync(obj, key)); + + if (_characterBuildCache.TryGetValue(key, out cached)) + { + var completed = await Task.WhenAny(buildTask, Task.Delay(_softReturnIfBusyAfter, ct)).ConfigureAwait(false); + if (completed != buildTask && (DateTime.UtcNow - cached.CreatedUtc) <= TimeSpan.FromSeconds(5)) + { + return cached.Fragment; + } + } + + return await WithCancellation(buildTask, ct).ConfigureAwait(false); + } + + private async Task BuildAndCacheAsync(GameObjectHandler obj, nint key) + { + try + { + using var cts = new CancellationTokenSource(_hardBuildTimeout); + var fragment = await CreateCharacterDataInternal(obj, cts.Token).ConfigureAwait(false); + + _characterBuildCache[key] = new CacheEntry(fragment, DateTime.UtcNow); + PruneCharacterCacheIfNeeded(); + + return fragment; + } + finally + { + _characterBuildInflight.TryRemove(key, out _); + } + } + + private void PruneCharacterCacheIfNeeded() + { + if (_characterBuildCache.Count < 2048) return; + + var cutoff = DateTime.UtcNow - TimeSpan.FromSeconds(10); + foreach (var kv in _characterBuildCache) + { + if (kv.Value.CreatedUtc < cutoff) + _characterBuildCache.TryRemove(kv.Key, out _); + } + } + + private static async Task WithCancellation(Task task, CancellationToken ct) + => await task.WaitAsync(ct).ConfigureAwait(false); + + private async Task CreateCharacterDataInternal(GameObjectHandler playerRelatedObject, CancellationToken ct) { var objectKind = playerRelatedObject.ObjectKind; CharacterDataFragment fragment = objectKind == ObjectKind.Player ? new CharacterDataFragmentPlayer() : new(); - _logger.LogDebug("Building character data for {obj}", playerRelatedObject); var logDebug = _logger.IsEnabled(LogLevel.Debug); + var sw = Stopwatch.StartNew(); - await _dalamudUtil.WaitWhileCharacterIsDrawing(_logger, playerRelatedObject, Guid.NewGuid(), 30000, ct: ct).ConfigureAwait(false); - int totalWaitTime = 10000; - while (!await _dalamudUtil.IsObjectPresentAsync(await _dalamudUtil.CreateGameObjectAsync(playerRelatedObject.Address).ConfigureAwait(false)).ConfigureAwait(false) && totalWaitTime > 0) - { - _logger.LogTrace("Character is null but it shouldn't be, waiting"); - await Task.Delay(50, ct).ConfigureAwait(false); - totalWaitTime -= 50; - } + _logger.LogDebug("Building character data for {obj}", playerRelatedObject); + + await EnsureObjectPresentAsync(playerRelatedObject, ct).ConfigureAwait(false); + ct.ThrowIfCancellationRequested(); + + var waitRecordingTask = _transientResourceManager.WaitForRecording(ct); + + await _dalamudUtil.WaitWhileCharacterIsDrawing(_logger, playerRelatedObject, Guid.NewGuid(), 30000, ct: ct) + .ConfigureAwait(false); ct.ThrowIfCancellationRequested(); - DateTime start = DateTime.UtcNow; - - Dictionary>? resolvedPaths; - - resolvedPaths = (await _ipcManager.Penumbra.GetCharacterData(_logger, playerRelatedObject).ConfigureAwait(false)); - if (resolvedPaths == null) throw new InvalidOperationException("Penumbra returned null data"); - - ct.ThrowIfCancellationRequested(); - - var fileReplacementsTask = Task.Run(() => - { - var replacements = new HashSet( - resolvedPaths.Select(c => new FileReplacement([.. c.Value], c.Key)), - FileReplacementComparer.Instance) - .Where(p => p.HasFileReplacement) - .ToHashSet(); - - replacements.RemoveWhere(c => c.GamePaths.Any(g => - !CacheMonitor.AllowedFileExtensions.Any(e => - g.EndsWith(e, StringComparison.OrdinalIgnoreCase)))); - - return replacements; - }, ct); - - ct.ThrowIfCancellationRequested(); + if (await CheckForNullDrawObject(playerRelatedObject.Address).ConfigureAwait(false)) + throw new InvalidOperationException("DrawObject became null during build (actor despawned)"); + Task getGlamourerData = _ipcManager.Glamourer.GetCharacterCustomizationAsync(playerRelatedObject.Address); + Task getCustomizeData = _ipcManager.CustomizePlus.GetScaleAsync(playerRelatedObject.Address); + Task? getMoodlesData = null; Task? getHeelsOffset = null; - Task? getGlamourerData = null; - Task? getCustomizeData = null; Task? getHonorificTitle = null; - Task? getMoodlesData = null; if (objectKind == ObjectKind.Player) { getHeelsOffset = _ipcManager.Heels.GetOffsetAsync(); - getGlamourerData = _ipcManager.Glamourer.GetCharacterCustomizationAsync(playerRelatedObject.Address); - getCustomizeData = _ipcManager.CustomizePlus.GetScaleAsync(playerRelatedObject.Address); getHonorificTitle = _ipcManager.Honorific.GetTitle(); getMoodlesData = _ipcManager.Moodles.GetStatusAsync(playerRelatedObject.Address); } - else - { - getGlamourerData = _ipcManager.Glamourer.GetCharacterCustomizationAsync(playerRelatedObject.Address); - getCustomizeData = _ipcManager.CustomizePlus.GetScaleAsync(playerRelatedObject.Address); - } - fragment.FileReplacements = await fileReplacementsTask.ConfigureAwait(false); + var resolvedPaths = await _ipcManager.Penumbra.GetCharacterData(_logger, playerRelatedObject).ConfigureAwait(false) ?? throw new InvalidOperationException("Penumbra returned null data; couldn't proceed with character"); + ct.ThrowIfCancellationRequested(); + + var staticBuildTask = Task.Run(() => BuildStaticReplacements(resolvedPaths), ct); + + fragment.FileReplacements = await staticBuildTask.ConfigureAwait(false); if (logDebug) { _logger.LogDebug("== Static Replacements =="); - foreach (var replacement in fragment.FileReplacements.Where(i => i.HasFileReplacement).OrderBy(i => i.GamePaths.First(), StringComparer.OrdinalIgnoreCase)) + foreach (var replacement in fragment.FileReplacements + .Where(i => i.HasFileReplacement) + .OrderBy(i => i.GamePaths.First(), StringComparer.OrdinalIgnoreCase)) { _logger.LogDebug("=> {repl}", replacement); ct.ThrowIfCancellationRequested(); } } - else - { - foreach (var replacement in fragment.FileReplacements.Where(i => i.HasFileReplacement)) - { - ct.ThrowIfCancellationRequested(); - } - } - var staticReplacements = fragment.FileReplacements.ToHashSet(); + var staticReplacements = new HashSet(fragment.FileReplacements, FileReplacementComparer.Instance); - Task<(IReadOnlyDictionary ResolvedPaths, HashSet? ClearedReplacements)> transientTask = ProcessTransientDataAsync( - objectKind, + var transientTask = ResolveTransientReplacementsAsync( playerRelatedObject, + objectKind, staticReplacements, + waitRecordingTask, ct); + fragment.GlamourerString = await getGlamourerData.ConfigureAwait(false); + _logger.LogDebug("Glamourer is now: {data}", fragment.GlamourerString); + + var customizeScale = await getCustomizeData.ConfigureAwait(false); + fragment.CustomizePlusScale = customizeScale ?? string.Empty; + _logger.LogDebug("Customize is now: {data}", fragment.CustomizePlusScale); + + if (objectKind == ObjectKind.Player) + { + CharacterDataFragmentPlayer? playerFragment = fragment as CharacterDataFragmentPlayer ?? throw new InvalidOperationException("Failed to cast CharacterDataFragment to Player variant"); + + playerFragment.ManipulationString = _ipcManager.Penumbra.GetMetaManipulations(); + playerFragment.HonorificData = await getHonorificTitle!.ConfigureAwait(false); + _logger.LogDebug("Honorific is now: {data}", playerFragment!.HonorificData); + + playerFragment.PetNamesData = _ipcManager.PetNames.GetLocalNames(); + _logger.LogDebug("Pet Nicknames is now: {petnames}", playerFragment!.PetNamesData); + + playerFragment.HeelsData = await getHeelsOffset!.ConfigureAwait(false); + _logger.LogDebug("Heels is now: {heels}", playerFragment!.HeelsData); + + playerFragment.MoodlesData = (await getMoodlesData!.ConfigureAwait(false)) ?? string.Empty; + _logger.LogDebug("Moodles is now: {moodles}", playerFragment!.MoodlesData); + } + ct.ThrowIfCancellationRequested(); var (resolvedTransientPaths, clearedForPet) = await transientTask.ConfigureAwait(false); - if (clearedForPet != null) - { fragment.FileReplacements.Clear(); - } if (logDebug) { _logger.LogDebug("== Transient Replacements =="); - foreach (var replacement in resolvedTransientPaths.Select(c => new FileReplacement([.. c.Value], c.Key)).OrderBy(f => f.ResolvedPath, StringComparer.Ordinal)) + foreach (var replacement in resolvedTransientPaths + .Select(c => new FileReplacement([.. c.Value], c.Key)) + .OrderBy(f => f.ResolvedPath, StringComparer.Ordinal)) { _logger.LogDebug("=> {repl}", replacement); fragment.FileReplacements.Add(replacement); @@ -227,40 +300,16 @@ public class PlayerDataFactory else { foreach (var replacement in resolvedTransientPaths.Select(c => new FileReplacement([.. c.Value], c.Key))) - { fragment.FileReplacements.Add(replacement); - } } _transientResourceManager.CleanUpSemiTransientResources(objectKind, [.. fragment.FileReplacements]); - ct.ThrowIfCancellationRequested(); - - fragment.FileReplacements = new HashSet(fragment.FileReplacements.Where(v => v.HasFileReplacement).OrderBy(v => v.ResolvedPath, StringComparer.Ordinal), FileReplacementComparer.Instance); - - fragment.GlamourerString = await getGlamourerData.ConfigureAwait(false); - _logger.LogDebug("Glamourer is now: {data}", fragment.GlamourerString); - var customizeScale = await getCustomizeData.ConfigureAwait(false); - fragment.CustomizePlusScale = customizeScale ?? string.Empty; - _logger.LogDebug("Customize is now: {data}", fragment.CustomizePlusScale); - - if (objectKind == ObjectKind.Player) - { - var playerFragment = (fragment as CharacterDataFragmentPlayer)!; - playerFragment.ManipulationString = _ipcManager.Penumbra.GetMetaManipulations(); - - playerFragment!.HonorificData = await getHonorificTitle!.ConfigureAwait(false); - _logger.LogDebug("Honorific is now: {data}", playerFragment!.HonorificData); - - playerFragment!.HeelsData = await getHeelsOffset!.ConfigureAwait(false); - _logger.LogDebug("Heels is now: {heels}", playerFragment!.HeelsData); - - playerFragment!.MoodlesData = await getMoodlesData!.ConfigureAwait(false) ?? string.Empty; - _logger.LogDebug("Moodles is now: {moodles}", playerFragment!.MoodlesData); - - playerFragment!.PetNamesData = _ipcManager.PetNames.GetLocalNames(); - _logger.LogDebug("Pet Nicknames is now: {petnames}", playerFragment!.PetNamesData); - } + fragment.FileReplacements = new HashSet( + fragment.FileReplacements + .Where(v => v.HasFileReplacement) + .OrderBy(v => v.ResolvedPath, StringComparer.Ordinal), + FileReplacementComparer.Instance); ct.ThrowIfCancellationRequested(); @@ -269,7 +318,7 @@ public class PlayerDataFactory await Task.Run(() => { - var computedPaths = _fileCacheManager.GetFileCachesByPaths(toCompute.Select(c => c.ResolvedPath).ToArray()); + var computedPaths = _fileCacheManager.GetFileCachesByPaths([.. toCompute.Select(c => c.ResolvedPath)]); foreach (var file in toCompute) { ct.ThrowIfCancellationRequested(); @@ -279,9 +328,7 @@ public class PlayerDataFactory var removed = fragment.FileReplacements.RemoveWhere(f => !f.IsFileSwap && string.IsNullOrEmpty(f.Hash)); if (removed > 0) - { _logger.LogDebug("Removed {amount} of invalid files", removed); - } ct.ThrowIfCancellationRequested(); @@ -299,21 +346,16 @@ public class PlayerDataFactory .RunOnFrameworkThread(() => _modelAnalyzer.GetSkeletonBoneIndices(playerRelatedObject)) .ConfigureAwait(false); } - } - if (objectKind == ObjectKind.Player) - { try { #if DEBUG if (hasPapFiles && boneIndices != null) - { _modelAnalyzer.DumpLocalSkeletonIndices(playerRelatedObject); - } #endif if (hasPapFiles) { - await VerifyPlayerAnimationBones(boneIndices, (fragment as CharacterDataFragmentPlayer)!, ct) + await VerifyPlayerAnimationBones(boneIndices, (CharacterDataFragmentPlayer)fragment, ct) .ConfigureAwait(false); } } @@ -328,11 +370,94 @@ public class PlayerDataFactory } } - _logger.LogInformation("Building character data for {obj} took {time}ms", objectKind, TimeSpan.FromTicks(DateTime.UtcNow.Ticks - start.Ticks).TotalMilliseconds); + _logger.LogInformation("Building character data for {obj} took {time}ms", + objectKind, sw.Elapsed.TotalMilliseconds); return fragment; } + private async Task EnsureObjectPresentAsync(GameObjectHandler handler, CancellationToken ct) + { + var remaining = 10000; + while (remaining > 0) + { + ct.ThrowIfCancellationRequested(); + + var obj = await _dalamudUtil.CreateGameObjectAsync(handler.Address).ConfigureAwait(false); + if (await _dalamudUtil.IsObjectPresentAsync(obj).ConfigureAwait(false)) + return; + + _logger.LogTrace("Character is null but it shouldn't be, waiting"); + await Task.Delay(50, ct).ConfigureAwait(false); + remaining -= 50; + } + } + + private static HashSet BuildStaticReplacements(Dictionary> resolvedPaths) + { + var set = new HashSet(FileReplacementComparer.Instance); + + foreach (var kvp in resolvedPaths) + { + var fr = new FileReplacement([.. kvp.Value], kvp.Key); + if (!fr.HasFileReplacement) continue; + + var allAllowed = fr.GamePaths.All(g => + CacheMonitor.AllowedFileExtensions.Any(e => g.EndsWith(e, StringComparison.OrdinalIgnoreCase))); + + if (!allAllowed) continue; + + set.Add(fr); + } + + return set; + } + + private async Task<(IReadOnlyDictionary ResolvedPaths, HashSet? ClearedReplacements)> + ResolveTransientReplacementsAsync( + GameObjectHandler obj, + ObjectKind objectKind, + HashSet staticReplacements, + Task waitRecordingTask, + CancellationToken ct) + { + await waitRecordingTask.ConfigureAwait(false); + + HashSet? clearedReplacements = null; + + if (objectKind == ObjectKind.Pet) + { + foreach (var item in staticReplacements.Where(i => i.HasFileReplacement).SelectMany(p => p.GamePaths)) + { + if (_transientResourceManager.AddTransientResource(objectKind, item)) + _logger.LogDebug("Marking static {item} for Pet as transient", item); + } + + _logger.LogTrace("Clearing {count} Static Replacements for Pet", staticReplacements.Count); + clearedReplacements = staticReplacements; + } + + ct.ThrowIfCancellationRequested(); + + _transientResourceManager.ClearTransientPaths(objectKind, [.. staticReplacements.SelectMany(c => c.GamePaths)]); + + var transientPaths = ManageSemiTransientData(objectKind); + if (transientPaths.Count == 0) + return (new Dictionary(StringComparer.Ordinal), clearedReplacements); + + var resolved = await GetFileReplacementsFromPaths(obj, transientPaths, new HashSet(StringComparer.Ordinal)) + .ConfigureAwait(false); + + if (_maxTransientResolvedEntries > 0 && resolved.Count > _maxTransientResolvedEntries) + { + _logger.LogWarning("Transient entries ({resolved}) are above the threshold {max}; Please consider disable some mods (VFX have heavy load) to reduce transient load", + resolved.Count, + _maxTransientResolvedEntries); + } + + return (resolved, clearedReplacements); + } + private async Task VerifyPlayerAnimationBones( Dictionary>? playerBoneIndices, CharacterDataFragmentPlayer fragment, @@ -347,12 +472,13 @@ public class PlayerDataFactory { if (indices == null || indices.Count == 0) continue; + var key = XivDataAnalyzer.CanonicalizeSkeletonKey(rawLocalKey); if (string.IsNullOrEmpty(key)) continue; if (!playerBoneSets.TryGetValue(key, out var set)) - playerBoneSets[key] = set = new HashSet(); + playerBoneSets[key] = set = []; foreach (var idx in indices) set.Add(idx); @@ -361,18 +487,6 @@ public class PlayerDataFactory if (playerBoneSets.Count == 0) return; - if (_logger.IsEnabled(LogLevel.Debug)) - { - foreach (var kvp in playerBoneSets) - { - _logger.LogDebug( - "Found local skeleton bucket '{bucket}' ({count} indices, max {max})", - kvp.Key, - kvp.Value.Count, - kvp.Value.Count > 0 ? kvp.Value.Max() : 0); - } - } - var papFiles = fragment.FileReplacements .Where(f => !f.IsFileSwap && f.GamePaths.First().EndsWith("pap", StringComparison.OrdinalIgnoreCase)) .ToList(); @@ -414,7 +528,6 @@ public class PlayerDataFactory ct.ThrowIfCancellationRequested(); var hash = group.Key; - Dictionary>? papSkeletonIndices; await _papParseLimiter.WaitAsync(ct).ConfigureAwait(false); @@ -432,10 +545,7 @@ public class PlayerDataFactory continue; if (ShouldIgnorePap(papSkeletonIndices)) - { - _logger.LogTrace("All indices of PAP hash {hash} are <= 105, ignoring", hash); continue; - } bool invalid = false; string? reason = null; @@ -480,7 +590,6 @@ public class PlayerDataFactory foreach (var file in group.ToList()) { - _logger.LogDebug("Removing {file} from sent file replacements and transient data", file.ResolvedPath); fragment.FileReplacements.Remove(file); foreach (var gamePath in file.GamePaths) @@ -500,75 +609,30 @@ public class PlayerDataFactory } } - private async Task<(IReadOnlyDictionary ResolvedPaths, HashSet? ClearedReplacements)> ProcessTransientDataAsync( - ObjectKind objectKind, - GameObjectHandler playerRelatedObject, - HashSet staticReplacements, - CancellationToken ct) - { - await _transientResourceManager.WaitForRecording(ct).ConfigureAwait(false); - - HashSet? clearedReplacements = null; - - var gamePaths = staticReplacements - .Where(i => i.HasFileReplacement) - .SelectMany(p => p.GamePaths) - .ToList(); - - if (objectKind == ObjectKind.Pet) - { - foreach (var item in gamePaths) - { - if (_transientResourceManager.AddTransientResource(objectKind, item)) - { - _logger.LogDebug("Marking static {item} for Pet as transient", item); - } - } - - _logger.LogTrace("Clearing {count} Static Replacements for Pet", staticReplacements.Count); - clearedReplacements = staticReplacements; - } - - ct.ThrowIfCancellationRequested(); - - _transientResourceManager.ClearTransientPaths(objectKind, gamePaths); - - var transientPaths = ManageSemiTransientData(objectKind); - IReadOnlyDictionary resolved = await GetFileReplacementsFromPaths( - playerRelatedObject, - transientPaths, - new HashSet(StringComparer.Ordinal)).ConfigureAwait(false); - - return (resolved, clearedReplacements); - } - - - private async Task> GetFileReplacementsFromPaths(GameObjectHandler handler, HashSet forwardResolve, HashSet reverseResolve) + private async Task> GetFileReplacementsFromPaths( + GameObjectHandler handler, + HashSet forwardResolve, + HashSet reverseResolve) { var forwardPaths = forwardResolve.ToArray(); var reversePaths = reverseResolve.ToArray(); Dictionary> resolvedPaths = new(StringComparer.Ordinal); + if (handler.ObjectKind != ObjectKind.Player) { var (objectIndex, forwardResolved, reverseResolved) = await _dalamudUtil.RunOnFrameworkThread(() => { var idx = handler.GetGameObject()?.ObjectIndex; if (!idx.HasValue) - { return ((int?)null, Array.Empty(), Array.Empty()); - } var resolvedForward = new string[forwardPaths.Length]; for (int i = 0; i < forwardPaths.Length; i++) - { resolvedForward[i] = _ipcManager.Penumbra.ResolveGameObjectPath(forwardPaths[i], idx.Value); - } var resolvedReverse = new string[reversePaths.Length][]; for (int i = 0; i < reversePaths.Length; i++) - { resolvedReverse[i] = _ipcManager.Penumbra.ReverseResolveGameObjectPath(reversePaths[i], idx.Value); - } return (idx, resolvedForward, resolvedReverse); }).ConfigureAwait(false); @@ -579,31 +643,21 @@ public class PlayerDataFactory { var filePath = forwardResolved[i]?.ToLowerInvariant(); if (string.IsNullOrEmpty(filePath)) - { continue; - } if (resolvedPaths.TryGetValue(filePath, out var list)) - { list.Add(forwardPaths[i].ToLowerInvariant()); - } else - { resolvedPaths[filePath] = [forwardPaths[i].ToLowerInvariant()]; - } } for (int i = 0; i < reversePaths.Length; i++) { var filePath = reversePaths[i].ToLowerInvariant(); if (resolvedPaths.TryGetValue(filePath, out var list)) - { list.AddRange(reverseResolved[i].Select(c => c.ToLowerInvariant())); - } else - { - resolvedPaths[filePath] = new List(reverseResolved[i].Select(c => c.ToLowerInvariant()).ToList()); - } + resolvedPaths[filePath] = [.. reverseResolved[i].Select(c => c.ToLowerInvariant()).ToList()]; } return resolvedPaths.ToDictionary(k => k.Key, k => k.Value.ToArray(), StringComparer.OrdinalIgnoreCase).AsReadOnly(); @@ -611,30 +665,23 @@ public class PlayerDataFactory } var (forward, reverse) = await _ipcManager.Penumbra.ResolvePathsAsync(forwardPaths, reversePaths).ConfigureAwait(false); + for (int i = 0; i < forwardPaths.Length; i++) { var filePath = forward[i].ToLowerInvariant(); if (resolvedPaths.TryGetValue(filePath, out var list)) - { list.Add(forwardPaths[i].ToLowerInvariant()); - } else - { resolvedPaths[filePath] = [forwardPaths[i].ToLowerInvariant()]; - } } for (int i = 0; i < reversePaths.Length; i++) { var filePath = reversePaths[i].ToLowerInvariant(); if (resolvedPaths.TryGetValue(filePath, out var list)) - { list.AddRange(reverse[i].Select(c => c.ToLowerInvariant())); - } else - { resolvedPaths[filePath] = new List(reverse[i].Select(c => c.ToLowerInvariant()).ToList()); - } } return resolvedPaths.ToDictionary(k => k.Key, k => k.Value.ToArray(), StringComparer.OrdinalIgnoreCase).AsReadOnly(); @@ -645,11 +692,29 @@ public class PlayerDataFactory _transientResourceManager.PersistTransientResources(objectKind); HashSet pathsToResolve = new(StringComparer.Ordinal); - foreach (var path in _transientResourceManager.GetSemiTransientResources(objectKind).Where(path => !string.IsNullOrEmpty(path))) + + int scanned = 0, skippedEmpty = 0, skippedVfx = 0; + + foreach (var path in _transientResourceManager.GetSemiTransientResources(objectKind)) { + scanned++; + + if (string.IsNullOrEmpty(path)) + { + skippedEmpty++; + continue; + } + pathsToResolve.Add(path); } + if (_logger.IsEnabled(LogLevel.Debug)) + { + _logger.LogDebug( + "ManageSemiTransientData({kind}): scanned={scanned}, added={added}, skippedEmpty={skippedEmpty}, skippedVfx={skippedVfx}", + objectKind, scanned, pathsToResolve.Count, skippedEmpty, skippedVfx); + } + return pathsToResolve; } -} \ No newline at end of file +} diff --git a/LightlessSync/Services/DalamudUtilService.cs b/LightlessSync/Services/DalamudUtilService.cs index b278667..f47512a 100644 --- a/LightlessSync/Services/DalamudUtilService.cs +++ b/LightlessSync/Services/DalamudUtilService.cs @@ -22,8 +22,10 @@ using LightlessSync.Utils; using Lumina.Excel.Sheets; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; +using System.Diagnostics; using System.Numerics; using System.Runtime.CompilerServices; +using System.Runtime.InteropServices; using System.Text; using BattleNpcSubKind = FFXIVClientStructs.FFXIV.Client.Game.Object.BattleNpcSubKind; using DalamudObjectKind = Dalamud.Game.ClientState.Objects.Enums.ObjectKind; @@ -843,31 +845,41 @@ public class DalamudUtilService : IHostedService, IMediatorSubscriber return Task.CompletedTask; } - public async Task WaitWhileCharacterIsDrawing(ILogger logger, GameObjectHandler handler, Guid redrawId, int timeOut = 5000, CancellationToken? ct = null) + public async Task WaitWhileCharacterIsDrawing( + ILogger logger, + GameObjectHandler handler, + Guid redrawId, + int timeOut = 5000, + CancellationToken? ct = null) { if (!_clientState.IsLoggedIn) return; - if (ct == null) - ct = CancellationToken.None; + var token = ct ?? CancellationToken.None; + + const int tick = 250; + const int initialSettle = 50; + + var sw = Stopwatch.StartNew(); - const int tick = 250; - int curWaitTime = 0; try { logger.LogTrace("[{redrawId}] Starting wait for {handler} to draw", redrawId, handler); - await Task.Delay(tick, ct.Value).ConfigureAwait(true); - curWaitTime += tick; - while ((!ct.Value.IsCancellationRequested) - && curWaitTime < timeOut - && await handler.IsBeingDrawnRunOnFrameworkAsync().ConfigureAwait(false)) // 0b100000000000 is "still rendering" or something + await Task.Delay(initialSettle, token).ConfigureAwait(false); + + while (!token.IsCancellationRequested + && sw.ElapsedMilliseconds < timeOut + && await handler.IsBeingDrawnRunOnFrameworkAsync().ConfigureAwait(false)) { logger.LogTrace("[{redrawId}] Waiting for {handler} to finish drawing", redrawId, handler); - curWaitTime += tick; - await Task.Delay(tick, ct.Value).ConfigureAwait(true); + await Task.Delay(tick, token).ConfigureAwait(false); } - logger.LogTrace("[{redrawId}] Finished drawing after {curWaitTime}ms", redrawId, curWaitTime); + logger.LogTrace("[{redrawId}] Finished drawing after {ms}ms", redrawId, sw.ElapsedMilliseconds); + } + catch (OperationCanceledException) + { + // ignore } catch (AccessViolationException ex) {