From f3f2de333727faaf2ca9f99c9e712e0073efac5d Mon Sep 17 00:00:00 2001 From: bd_ Date: Sat, 28 Sep 2024 18:17:50 -0700 Subject: [PATCH] feat: add tracing points for the NDMF preview tracing system --- .github/ProjectRoot/vpm-manifest-2022.json | 2 +- .../AnimationGeneration/PropCache.cs | 78 ++++++++++++++++--- .../ReactiveObjects/Simulator/ROSimulator.cs | 22 +++++- package.json | 2 +- 4 files changed, 91 insertions(+), 13 deletions(-) diff --git a/.github/ProjectRoot/vpm-manifest-2022.json b/.github/ProjectRoot/vpm-manifest-2022.json index cdf4ad72..d4a80444 100644 --- a/.github/ProjectRoot/vpm-manifest-2022.json +++ b/.github/ProjectRoot/vpm-manifest-2022.json @@ -19,7 +19,7 @@ "dependencies": {} }, "nadena.dev.ndmf": { - "version": "1.5.0-rc.8" + "version": "1.5.0-rc.11" } } } \ No newline at end of file diff --git a/Editor/ReactiveObjects/AnimationGeneration/PropCache.cs b/Editor/ReactiveObjects/AnimationGeneration/PropCache.cs index e0063697..ec87a881 100644 --- a/Editor/ReactiveObjects/AnimationGeneration/PropCache.cs +++ b/Editor/ReactiveObjects/AnimationGeneration/PropCache.cs @@ -1,6 +1,7 @@ using System; using System.Collections.Generic; using nadena.dev.ndmf.preview; +using nadena.dev.ndmf.preview.trace; namespace nadena.dev.modular_avatar.core.editor { @@ -13,6 +14,7 @@ namespace nadena.dev.modular_avatar.core.editor public Key Key; public Value Value; public string DebugName; + public int Generation; } private readonly string _debugName; @@ -20,6 +22,8 @@ namespace nadena.dev.modular_avatar.core.editor private readonly Func _equalityComparer; private readonly Dictionary _cache = new(); + private static int _generation = 0; + public PropCache(string debugName, Func operatorFunc, Func equalityComparer = null) { @@ -30,41 +34,97 @@ namespace nadena.dev.modular_avatar.core.editor private static void InvalidateEntry(CacheEntry entry) { - var newGenContext = new ComputeContext("PropCache/" + entry.DebugName + " key " + entry.Key); + var newGenContext = new ComputeContext("PropCache/" + entry.DebugName + " key " + FormatKey(entry.Key) + " gen=" + _generation++); var newValue = entry.Owner._operator(newGenContext, entry.Key); - if (entry.Owner._equalityComparer != null && entry.Owner._equalityComparer(entry.Value, newValue)) + if (!entry.ObserverContext.IsInvalidated && entry.Owner._equalityComparer != null && entry.Owner._equalityComparer(entry.Value, newValue)) { + TraceBuffer.RecordTraceEvent( + "PropCache.InvalidateEntry", + (ev) => $"[PropCache/{ev.Arg0}] Value did not change, retaining result (new gen={ev.Arg1})", + entry.DebugName, entry.Generation + ); + entry.GenerateContext = newGenContext; entry.GenerateContext.InvokeOnInvalidate(entry, InvalidateEntry); return; } + var trace = TraceBuffer.RecordTraceEvent( + "PropCache.InvalidateEntry", + (ev) => $"[PropCache/{ev.Arg0}] Value changed, invalidating", + entry.DebugName + ); + entry.Owner._cache.Remove(entry.Key); - entry.ObserverContext.Invalidate(); + using (trace.Scope()) entry.ObserverContext.Invalidate(); } public Value Get(ComputeContext context, Key key) { + TraceEvent ev; + var formattedKey = FormatKey(key); if (!_cache.TryGetValue(key, out var entry) || entry.GenerateContext.IsInvalidated) { - var subContext = new ComputeContext("PropCache/" + _debugName + " key " + key); + var curGen = _generation++; + + var subContext = new ComputeContext("PropCache/" + _debugName + " key " + formattedKey + " gen=" + curGen); entry = new CacheEntry { GenerateContext = subContext, - ObserverContext = new ComputeContext("Observer for PropCache for key " + key), + ObserverContext = new ComputeContext("Observer for PropCache/" + _debugName + " for key " + + formattedKey + " gen=" + curGen), Owner = this, Key = key, - Value = _operator(subContext, key), - DebugName = _debugName + DebugName = _debugName, + Generation = curGen }; + + ev = TraceBuffer.RecordTraceEvent( + "PropCache.Get", + (ev) => + { + var entry_ = (CacheEntry)ev.Arg0; + return + $"[PropCache/{entry_.DebugName}] Cache miss for key {entry_.Key} gen={entry_.Generation} from context {ev.Arg1}"; + }, + entry, context + ); + _cache[key] = entry; - - subContext.InvokeOnInvalidate(entry, InvalidateEntry); + using (ev.Scope()) + { + entry.Value = _operator(subContext, key); + entry.GenerateContext.InvokeOnInvalidate(entry, InvalidateEntry); + } + } + else + { + ev = TraceBuffer.RecordTraceEvent( + "PropCache.Get", + (ev) => + { + var entry_ = (CacheEntry) ev.Arg0; + return $"[PropCache/{entry_.DebugName}] Cache hit for key {entry_.Key} gen={entry_.Generation} from context {ev.Arg1}"; + }, + entry, context + ); } entry.ObserverContext.Invalidates(context); return entry.Value; } + + private static string FormatKey(object obj) + { + if (obj is UnityEngine.Object unityObj) + { + return $"{unityObj.GetHashCode()}#{unityObj}"; + } + else + { + return "" + obj; + } + } } } \ No newline at end of file diff --git a/Editor/ReactiveObjects/Simulator/ROSimulator.cs b/Editor/ReactiveObjects/Simulator/ROSimulator.cs index e34a7a40..c6bee26a 100644 --- a/Editor/ReactiveObjects/Simulator/ROSimulator.cs +++ b/Editor/ReactiveObjects/Simulator/ROSimulator.cs @@ -5,6 +5,7 @@ using System.Linq; using nadena.dev.modular_avatar.ui; using nadena.dev.ndmf.localization; using nadena.dev.ndmf.preview; +using nadena.dev.ndmf.preview.trace; using UnityEditor; using UnityEditor.UIElements; using UnityEngine; @@ -14,8 +15,8 @@ namespace nadena.dev.modular_avatar.core.editor.Simulator { internal class ROSimulator : EditorWindow, IHasCustomMenu { - public static PublishedValue> PropertyOverrides = new(null); - public static PublishedValue> MenuItemOverrides = new(null); + public static PublishedValue> PropertyOverrides = new(null, debugName: "ROSimulator.PropertyOverrides"); + public static PublishedValue> MenuItemOverrides = new(null, debugName: "ROSimulator.MenuItemOverrides"); internal static string ROOT_PATH = "Packages/nadena.dev.modular-avatar/Editor/ReactiveObjects/Simulator/"; private static string USS = ROOT_PATH + "ROSimulator.uss"; @@ -106,6 +107,14 @@ namespace nadena.dev.modular_avatar.core.editor.Simulator private void UpdatePropertyOverride(string prop, bool? enable, float f_val) { + var trace = TraceBuffer.RecordTraceEvent( + "ROSimulator.UpdatePropertyOverride", + (ev) => $"Property {ev.Arg0} set to {ev.Arg1}", + arg0: prop, + arg1: enable == null ? "null" : enable.Value ? f_val : 0f + ); + + using (trace.Scope()) if (enable == null) { PropertyOverrides.Value = PropertyOverrides.Value.Remove(prop); @@ -123,6 +132,15 @@ namespace nadena.dev.modular_avatar.core.editor.Simulator private void UpdateMenuItemOverride(string prop, ModularAvatarMenuItem item, bool? value) { + var trace = TraceBuffer.RecordTraceEvent( + "ROSimulator.UpdateMenuItemOverride", + (ev) => $"MenuItem {ev.Arg0} for prop {ev.Arg1} set to {ev.Arg2}", + arg0: item.gameObject.name, + arg1: prop, + arg2: value == null ? "null" : value.Value ? "true" : "false" + ); + + using (trace.Scope()) if (value == null) { MenuItemOverrides.Value = MenuItemOverrides.Value.Remove(prop); diff --git a/package.json b/package.json index bf79dd83..96eaaecc 100644 --- a/package.json +++ b/package.json @@ -16,6 +16,6 @@ }, "vpmDependencies": { "com.vrchat.avatars": ">=3.7.0", - "nadena.dev.ndmf": ">=1.5.0-rc.10 <2.0.0-a" + "nadena.dev.ndmf": ">=1.5.0-rc.11 <2.0.0-a" } }