Performance optimization

[focustense]

This is a placeholder issue for ongoing performance optimization work.

After a lot of work on #18 and #44, I'm starting to see a lot of diminishing returns - operations such as dictionary lookups and string case conversions that ought to be in the nanosecond range taking milliseconds, possibly due to JIT overhead or even tracing overhead.

On a roughly 100 ms load of the Carousel demo, the breakdown translates to about:

• 30 ms of asset loading, which breaks down roughly to:
  • 10 ms for the view (reading the file and Document.Parse)
  • 10 ms for JSON loading of sprite data
  • 10 ms for other sprite loading tasks - lots of little quarter-ms and similar slices
• 30 ms in AttributeBindingFactory.TryCreateBinding, with:
  • 15 ms in CreateTypedBinding (actually creating the bindings)
  • 5 ms spent creating converters (RootValueConverter.TryGetConverter)
  • 2.5 ms spent in GetValueSource<T>
  • 3.5 ms spent in GetValueType
  • 1.5 ms spent in ToUpperCamelCase (for property names
  • 2.5 ms on dictionary lookups and misc overhead
• 10 ms in AttributeBinding.UpdateView, actually doing the updates for several dozen elements
• 7 ms in BinaryCondition.Update, of which:
  • 3 ms is BinaryCondition.Comparison.Create self-time (not converter factory)
  • 4 ms is unaccounted for
• 6.5 ms on CreateViewNode
• 5 ms on ReflectionObjectDescriptor.CreateDescriptor, with roughly equal contributions from:
  • DocumentViewMenu.ctor (descriptor for the root view model)
  • ForViewType on the custom Carousel view
  • RepeaterNode.UpdateChildBindings which is for the inner CarouselMenuPage type
• 3.5 ms on EventBindingFactory.TryCreateBinding (similar characteristics to Attributes)

Other miscellaneous stuff that's too small to even mention.

Maybe, possibly, there are some more opportunities for precompilation savings, but optimism is waning. This is very obviously a game of inches, it's hard to know for certain why certain things are slow, and of course this is only on the very first frame - once things are cached, the jank is never seen again even when the view is recreated. At this point, every 5-10 ms saved seems to take another few hours of analysis and tweaking, and it's going to take progressively longer for progressively smaller gains.

So I'm documenting these findings for the future, so I can close the major perf bugs now. While SDV is very, shall we say "variable" about times, the average has gone down from between almost 300 ms to slightly over 100 ms, and it's safe to say that all the low-hanging fruit has been picked.

Attached a trace for reference.

StardewUI_20241118_223329.json

[focustense]

One thing I failed to note above is that the Carousel example (intentionally) uses some bindings that generate warnings to the log, e.g. for non-updatable bindings that aren't explicitly one-time.

It's possible that at least some of the unexplained overhead is actually lock contention on the SMAPI log. Would be worth testing the example with those warnings suppressed or corrected to see if this makes a difference. It could be an easy ~10 ms of savings.

(The lock contention is a known issue with how SMAPI does its logging today)