removal of *temporary* collections

LightlessSync/Interop/Ipc/Penumbra/PenumbraCollections.cs

@@ -1,10 +1,8 @@
-using System.Collections.Concurrent;
 using Dalamud.Plugin;
 using LightlessSync.Interop.Ipc.Framework;
 using LightlessSync.Services;
 using LightlessSync.Services.Mediator;
 using Microsoft.Extensions.Logging;
-using Penumbra.Api.Enums;
 using Penumbra.Api.IpcSubscribers;
 
 namespace LightlessSync.Interop.Ipc.Penumbra;
@@ -16,10 +14,6 @@ public sealed class PenumbraCollections : PenumbraBase
     private readonly DeleteTemporaryCollection _removeTemporaryCollection;
     private readonly AddTemporaryMod _addTemporaryMod;
     private readonly RemoveTemporaryMod _removeTemporaryMod;
-    private readonly GetCollections _getCollections;
-    private readonly ConcurrentDictionary<Guid, string> _activeTemporaryCollections = new();
-
-    private int _cleanupScheduled;
 
     public PenumbraCollections(
         ILogger logger,
@@ -32,7 +26,6 @@ public sealed class PenumbraCollections : PenumbraBase
         _removeTemporaryCollection = new DeleteTemporaryCollection(pluginInterface);
         _addTemporaryMod = new AddTemporaryMod(pluginInterface);
         _removeTemporaryMod = new RemoveTemporaryMod(pluginInterface);
-        _getCollections = new GetCollections(pluginInterface);
     }
 
     public override string Name => "Penumbra.Collections";
@@ -62,16 +55,11 @@ public sealed class PenumbraCollections : PenumbraBase
         var (collectionId, collectionName) = await DalamudUtil.RunOnFrameworkThread(() =>
         {
             var name = $"Lightless_{uid}";
-            _createNamedTemporaryCollection.Invoke(name, name, out var tempCollectionId);
+            var createResult = _createNamedTemporaryCollection.Invoke(name, name, out var tempCollectionId);
-            logger.LogTrace("Creating Temp Collection {CollectionName}, GUID: {CollectionId}", name, tempCollectionId);
+            logger.LogTrace("Creating Temp Collection {CollectionName}, GUID: {CollectionId}, Result: {Result}", name, tempCollectionId, createResult);
             return (tempCollectionId, name);
         }).ConfigureAwait(false);
 
-        if (collectionId != Guid.Empty)
-        {
-            _activeTemporaryCollections[collectionId] = collectionName;
-        }
-
         return collectionId;
     }
 
@@ -89,7 +77,6 @@ public sealed class PenumbraCollections : PenumbraBase
             logger.LogTrace("[{ApplicationId}] RemoveTemporaryCollection: {Result}", applicationId, result);
         }).ConfigureAwait(false);
 
-        _activeTemporaryCollections.TryRemove(collectionId, out _);
     }
 
     public async Task SetTemporaryModsAsync(ILogger logger, Guid applicationId, Guid collectionId, Dictionary<string, string> modPaths)
@@ -131,67 +118,5 @@ public sealed class PenumbraCollections : PenumbraBase
 
     protected override void HandleStateChange(IpcConnectionState previous, IpcConnectionState current)
     {
-        if (current == IpcConnectionState.Available)
-        {
-            ScheduleCleanup();
-        }
-        else if (previous == IpcConnectionState.Available && current != IpcConnectionState.Available)
-        {
-            Interlocked.Exchange(ref _cleanupScheduled, 0);
-        }
     }
-
-    private void ScheduleCleanup()
-    {
-        if (Interlocked.Exchange(ref _cleanupScheduled, 1) != 0)
-        {
-            return;
-        }
-
-        _ = Task.Run(CleanupTemporaryCollectionsAsync);
-    }
-
-    private async Task CleanupTemporaryCollectionsAsync()
-    {
-        if (!IsAvailable)
-        {
-            return;
-        }
-
-        try
-        {
-            var collections = await DalamudUtil.RunOnFrameworkThread(() => _getCollections.Invoke()).ConfigureAwait(false);
-            foreach (var (collectionId, name) in collections)
-            {
-                if (!IsLightlessCollectionName(name) || _activeTemporaryCollections.ContainsKey(collectionId))
-                {
-                    continue;
-                }
-
-                Logger.LogDebug("Cleaning up stale temporary collection {CollectionName} ({CollectionId})", name, collectionId);
-                var deleteResult = await DalamudUtil.RunOnFrameworkThread(() =>
-                {
-                    var result = (PenumbraApiEc)_removeTemporaryCollection.Invoke(collectionId);
-                    Logger.LogTrace("Cleanup RemoveTemporaryCollection result for {CollectionName} ({CollectionId}): {Result}", name, collectionId, result);
-                    return result;
-                }).ConfigureAwait(false);
-
-                if (deleteResult == PenumbraApiEc.Success)
-                {
-                    _activeTemporaryCollections.TryRemove(collectionId, out _);
-                }
-                else
-                {
-                    Logger.LogDebug("Skipped removing temporary collection {CollectionName} ({CollectionId}). Result: {Result}", name, collectionId, deleteResult);
-                }
-            }
-        }
-        catch (Exception ex)
-        {
-            Logger.LogWarning(ex, "Failed to clean up Penumbra temporary collections");
-        }
-    }
-
-    private static bool IsLightlessCollectionName(string? name)
-        => !string.IsNullOrEmpty(name) && name.StartsWith("Lightless_", StringComparison.Ordinal);
 }

LightlessSync/Interop/Ipc/Penumbra/PenumbraResource.cs

@@ -4,6 +4,7 @@ using LightlessSync.PlayerData.Handlers;
 using LightlessSync.Services;
 using LightlessSync.Services.Mediator;
 using Microsoft.Extensions.Logging;
+using System.Diagnostics;
 using System.Globalization;
 using Penumbra.Api.Helpers;
 using Penumbra.Api.IpcSubscribers;
@@ -42,17 +43,33 @@ public sealed class PenumbraResource : PenumbraBase
             return null;
         }
 
-        return await DalamudUtil.RunOnFrameworkThread(() =>
+        var requestId = Guid.NewGuid();
+        var totalTimer = Stopwatch.StartNew();
+        logger.LogTrace("[{requestId}] Requesting Penumbra.GetGameObjectResourcePaths for {handler}", requestId, handler);
+
+        var result = await DalamudUtil.RunOnFrameworkThread(() =>
         {
-            logger.LogTrace("Calling On IPC: Penumbra.GetGameObjectResourcePaths");
             var idx = handler.GetGameObject()?.ObjectIndex;
             if (idx == null)
             {
+                logger.LogTrace("[{requestId}] GetGameObjectResourcePaths aborted (missing object index) for {handler}", requestId, handler);
                 return null;
             }
 
-            return _gameObjectResourcePaths.Invoke(idx.Value)[0];
+            logger.LogTrace("[{requestId}] Invoking Penumbra.GetGameObjectResourcePaths for index {index}", requestId, idx.Value);
+            var invokeTimer = Stopwatch.StartNew();
+            var data = _gameObjectResourcePaths.Invoke(idx.Value)[0];
+            invokeTimer.Stop();
+            logger.LogTrace("[{requestId}] Penumbra.GetGameObjectResourcePaths returned {count} entries in {elapsedMs}ms",
+                requestId, data?.Count ?? 0, invokeTimer.ElapsedMilliseconds);
+            return data;
         }).ConfigureAwait(false);
+
+        totalTimer.Stop();
+        logger.LogTrace("[{requestId}] Penumbra.GetGameObjectResourcePaths finished in {elapsedMs}ms (null: {isNull})",
+            requestId, totalTimer.ElapsedMilliseconds, result is null);
+
+        return result;
     }
 
     public string GetMetaManipulations()

LightlessSync/LightlessConfiguration/Configurations/LightlessConfig.cs

@@ -161,6 +161,7 @@ public class LightlessConfig : ILightlessConfiguration
     public string LastSeenVersion { get; set; } = string.Empty;
     public bool EnableParticleEffects { get; set; } = true;
     public HashSet<Guid> OrphanableTempCollections { get; set; } = [];
+    public List<OrphanableTempCollectionEntry> OrphanableTempCollectionEntries { get; set; } = [];
     public AnimationValidationMode AnimationValidationMode { get; set; } = AnimationValidationMode.Safe;
     public bool AnimationAllowOneBasedShift { get; set; } = true;
 

LightlessSync/LightlessConfiguration/Models/OrphanableTempCollectionEntry.cs

@@ -0,0 +1,7 @@
+namespace LightlessSync.LightlessConfiguration.Models;
+
+public sealed class OrphanableTempCollectionEntry
+{
+    public Guid Id { get; set; }
+    public DateTime RegisteredAtUtc { get; set; } = DateTime.MinValue;
+}

LightlessSync/PlayerData/Factories/PlayerDataFactory.cs

@@ -257,7 +257,28 @@ public class PlayerDataFactory
             getMoodlesData = _ipcManager.Moodles.GetStatusAsync(playerRelatedObject.Address);
         }
 
-        var resolvedPaths = await _ipcManager.Penumbra.GetCharacterData(_logger, playerRelatedObject).ConfigureAwait(false) ?? throw new InvalidOperationException("Penumbra returned null data; couldn't proceed with character");
+        Guid penumbraRequestId = Guid.Empty;
+        Stopwatch? penumbraSw = null;
+        if (logDebug)
+        {
+            penumbraRequestId = Guid.NewGuid();
+            penumbraSw = Stopwatch.StartNew();
+            _logger.LogDebug("Penumbra GetCharacterData start {id} for {obj}", penumbraRequestId, playerRelatedObject);
+        }
+
+        var resolvedPaths = await _ipcManager.Penumbra.GetCharacterData(_logger, playerRelatedObject).ConfigureAwait(false);
+
+        if (logDebug)
+        {
+            penumbraSw!.Stop();
+            _logger.LogDebug("Penumbra GetCharacterData done {id} in {elapsedMs}ms (count={count})",
+                penumbraRequestId,
+                penumbraSw.ElapsedMilliseconds,
+                resolvedPaths?.Count ?? -1);
+        }
+
+        if (resolvedPaths == null)
+            throw new InvalidOperationException("Penumbra returned null data; couldn't proceed with character");
         ct.ThrowIfCancellationRequested();
 
         var staticBuildTask = Task.Run(() => BuildStaticReplacements(resolvedPaths), ct);

LightlessSync/PlayerData/Pairs/IPairHandlerAdapter.cs

@@ -30,8 +30,6 @@ public interface IPairHandlerAdapter : IDisposable, IPairPerformanceSubject
     int MissingCriticalMods { get; }
     int MissingNonCriticalMods { get; }
     int MissingForbiddenMods { get; }
-    DateTime? InvisibleSinceUtc { get; }
-    DateTime? VisibilityEvictionDueAtUtc { get; }
 
     void Initialize();
     void ApplyData(CharacterData data);

LightlessSync/PlayerData/Pairs/Pair.cs

@@ -217,12 +217,6 @@ public class Pair
         if (handler is null)
             return PairDebugInfo.Empty;
 
-        var now = DateTime.UtcNow;
-        var dueAt = handler.VisibilityEvictionDueAtUtc;
-        var remainingSeconds = dueAt.HasValue
-            ? Math.Max(0, (dueAt.Value - now).TotalSeconds)
-            : (double?)null;
-
         return new PairDebugInfo(
             true,
             handler.Initialized,
@@ -231,9 +225,6 @@ public class Pair
             handler.LastDataReceivedAt,
             handler.LastApplyAttemptAt,
             handler.LastSuccessfulApplyAt,
-            handler.InvisibleSinceUtc,
-            handler.VisibilityEvictionDueAtUtc,
-            remainingSeconds,
             handler.LastFailureReason,
             handler.LastBlockingConditions,
             handler.IsApplying,

LightlessSync/PlayerData/Pairs/PairDebugInfo.cs

@@ -8,9 +8,6 @@ public sealed record PairDebugInfo(
     DateTime? LastDataReceivedAt,
     DateTime? LastApplyAttemptAt,
     DateTime? LastSuccessfulApplyAt,
-    DateTime? InvisibleSinceUtc,
-    DateTime? VisibilityEvictionDueAtUtc,
-    double? VisibilityEvictionRemainingSeconds,
     string? LastFailureReason,
     IReadOnlyList<string> BlockingConditions,
     bool IsApplying,
@@ -32,9 +29,6 @@ public sealed record PairDebugInfo(
         null,
         null,
         null,
-        null,
-        null,
-        null,
         Array.Empty<string>(),
         false,
         false,

LightlessSync/Services/PenumbraTempCollectionJanitor.cs

@@ -1,4 +1,6 @@
-using LightlessSync.Interop.Ipc;
+using System.Linq;
+using LightlessSync.Interop.Ipc;
+using LightlessSync.LightlessConfiguration.Models;
 using LightlessSync.LightlessConfiguration;
 using LightlessSync.Services.Mediator;
 using Microsoft.Extensions.Logging;
@@ -10,6 +12,7 @@ public sealed class PenumbraTempCollectionJanitor : DisposableMediatorSubscriber
     private readonly IpcManager _ipc;
     private readonly LightlessConfigService _config; 
     private int _ran;
+    private static readonly TimeSpan OrphanCleanupDelay = TimeSpan.FromDays(1);
 
     public PenumbraTempCollectionJanitor(
         ILogger<PenumbraTempCollectionJanitor> logger,
@@ -26,15 +29,46 @@ public sealed class PenumbraTempCollectionJanitor : DisposableMediatorSubscriber
     public void Register(Guid id)
     {
         if (id == Guid.Empty) return;
-        if (_config.Current.OrphanableTempCollections.Add(id))
+        var changed = false;
+        var config = _config.Current;
+        if (config.OrphanableTempCollections.Add(id))
+        {
+            changed = true;
+        }
+
+        var now = DateTime.UtcNow;
+        var existing = config.OrphanableTempCollectionEntries.FirstOrDefault(entry => entry.Id == id);
+        if (existing is null)
+        {
+            config.OrphanableTempCollectionEntries.Add(new OrphanableTempCollectionEntry
+            {
+                Id = id,
+                RegisteredAtUtc = now
+            });
+            changed = true;
+        }
+        else if (existing.RegisteredAtUtc == DateTime.MinValue)
+        {
+            existing.RegisteredAtUtc = now;
+            changed = true;
+        }
+
+        if (changed)
+        {
             _config.Save();
+        }
     }
 
     public void Unregister(Guid id)
     {
         if (id == Guid.Empty) return;
-        if (_config.Current.OrphanableTempCollections.Remove(id))
+        var config = _config.Current;
+        var changed = config.OrphanableTempCollections.Remove(id);
+        changed |= RemoveEntry(config.OrphanableTempCollectionEntries, id) > 0;
+        if (changed)
+        {
             _config.Save();
+        }
     }
 
     private void CleanupOrphansOnBoot()
@@ -45,14 +79,33 @@ public sealed class PenumbraTempCollectionJanitor : DisposableMediatorSubscriber
         if (!_ipc.Penumbra.APIAvailable)
             return;
 
-        var ids = _config.Current.OrphanableTempCollections.ToArray();
+        var config = _config.Current;
-        if (ids.Length == 0)
+        var ids = config.OrphanableTempCollections;
+        var entries = config.OrphanableTempCollectionEntries;
+        if (ids.Count == 0 && entries.Count == 0)
             return;
 
-        var appId = Guid.NewGuid();
+        var now = DateTime.UtcNow;
-        Logger.LogInformation("Cleaning up {count} orphaned Lightless temp collections found in configuration", ids.Length);
+        var changed = EnsureEntries(ids, entries, now);
+        var cutoff = now - OrphanCleanupDelay;
+        var expired = entries
+            .Where(entry => entry.Id != Guid.Empty && entry.RegisteredAtUtc != DateTime.MinValue && entry.RegisteredAtUtc <= cutoff)
+            .Select(entry => entry.Id)
+            .Distinct()
+            .ToList();
+        if (expired.Count == 0)
+        {
+            if (changed)
+            {
+                _config.Save();
+            }
+            return;
+        }
 
-        foreach (var id in ids)
+        var appId = Guid.NewGuid();
+        Logger.LogInformation("Cleaning up {count} orphaned Lightless temp collections older than {delay}", expired.Count, OrphanCleanupDelay);
+
+        foreach (var id in expired)
         {
             try
             {
@@ -65,7 +118,70 @@ public sealed class PenumbraTempCollectionJanitor : DisposableMediatorSubscriber
             }
         }
 
-        _config.Current.OrphanableTempCollections.Clear();
+        foreach (var id in expired)
+        {
+            ids.Remove(id);
+        }
+
+        foreach (var id in expired)
+        {
+            RemoveEntry(entries, id);
+        }
+
         _config.Save();
     }
-}
+
+    private static int RemoveEntry(List<OrphanableTempCollectionEntry> entries, Guid id)
+    {
+        var removed = 0;
+        for (var i = entries.Count - 1; i >= 0; i--)
+        {
+            if (entries[i].Id != id)
+            {
+                continue;
+            }
+
+            entries.RemoveAt(i);
+            removed++;
+        }
+
+        return removed;
+    }
+
+    private static bool EnsureEntries(HashSet<Guid> ids, List<OrphanableTempCollectionEntry> entries, DateTime now)
+    {
+        var changed = false;
+        foreach (var id in ids)
+        {
+            if (id == Guid.Empty)
+            {
+                continue;
+            }
+
+            if (entries.Any(entry => entry.Id == id))
+            {
+                continue;
+            }
+
+            entries.Add(new OrphanableTempCollectionEntry
+            {
+                Id = id,
+                RegisteredAtUtc = now
+            });
+            changed = true;
+        }
+
+        foreach (var entry in entries)
+        {
+            if (entry.Id == Guid.Empty || entry.RegisteredAtUtc != DateTime.MinValue)
+            {
+                continue;
+            }
+
+            entry.RegisteredAtUtc = now;
+            changed = true;
+        }
+
+        return changed;
+    }
+}

LightlessSync/UI/SettingsUi.cs

@@ -1485,8 +1485,6 @@ public class SettingsUi : WindowMediatorSubscriberBase
             DrawPairPropertyRow("Has Handler", FormatBool(debugInfo.HasHandler));
             DrawPairPropertyRow("Handler Initialized", FormatBool(debugInfo.HandlerInitialized));
             DrawPairPropertyRow("Handler Visible", FormatBool(debugInfo.HandlerVisible));
-            DrawPairPropertyRow("Last Time person rendered in", FormatTimestamp(debugInfo.InvisibleSinceUtc));
-            DrawPairPropertyRow("Handler Timer Temp Collection removal", FormatCountdown(debugInfo.VisibilityEvictionRemainingSeconds));
             DrawPairPropertyRow("Handler Scheduled For Deletion", FormatBool(debugInfo.HandlerScheduledForDeletion));
 
             DrawPairPropertyRow("Note", pair.GetNote() ?? "(none)");
@@ -1622,8 +1620,6 @@ public class SettingsUi : WindowMediatorSubscriberBase
         sb.AppendLine($"Has Handler: {FormatBool(debugInfo.HasHandler)}");
         sb.AppendLine($"Handler Initialized: {FormatBool(debugInfo.HandlerInitialized)}");
         sb.AppendLine($"Handler Visible: {FormatBool(debugInfo.HandlerVisible)}");
-        sb.AppendLine($"Last Time person rendered in: {FormatTimestamp(debugInfo.InvisibleSinceUtc)}");
-        sb.AppendLine($"Handler Timer Temp Collection removal: {FormatCountdown(debugInfo.VisibilityEvictionRemainingSeconds)}");
         sb.AppendLine($"Handler Scheduled For Deletion: {FormatBool(debugInfo.HandlerScheduledForDeletion)}");
         sb.AppendLine($"Note: {pair.GetNote() ?? "(none)"}");