506 Commits over 123 Days - 0.17cph!
Update: Gather GC.Collect activity into perf snapshot
- Avoid thread id checks reaching to mono runtime to resolve it, as it's unsafe during GC.Collect
Tests: did a 6k standalone perf snapshot, but didn't catch a collection event. Forced one in editor on 3rd frame, confirmed visible in perfetto.
Update: export Allocs as process-wide events
This puts them on a separate track, making it easier to spot them.
Tests: checked craggy snapshot in perfetto
Clean: removing some unnecessary sanitization logic
One of recent updates now guarantees storage is enough to house all snapshot data
Tests: loaded craggy snapshot in perfetto - no missing names/allocs, no asserts
Update: export Alloc events to json snapshot
They get a bit lost in the sea of all other instantaneous events, so will need to somehow improve this
Tests: loaded craggy snapshot in perfetto
Update: record GC alloc events in the snapshot
Currently don't emit them in the json, but that'll be the next thing
Tests: took a perf snapshot on craggy
Optim: reduce profiling capacity, instead lazy-grow it
- When frame didn't fit the capacity, drop it and rerecord it
This should help avoid large stutters in editor (and hopefully on the server as well).
Tests: tested craggy in editor - spikes gone. Tested on 6k world in standalone server - spikes still present. Also noticed one export failed, but think it's unrelated to current changes
Optim: Avoid allocations when generating method names
- Also cleaned up a couple TODOs
- Added extra logging to track stages of export progress
Getting very close to completing all outstanding TODOs
Tests: exported craggy and checked scope names in perfetto
Update: add cross-frame stitching of torn scopes
Tests: snapshotted craggy, loaded in perfetto
Update: offloading snapshot export to a task thread
- Stopped exporting binary snapshot, and left a comment explaining why it's not in use (but not deleted)
- Only export compressed json (saves a bit of time on iteration)
Hope is to reduce stutter, but my tests in editor show that it's inconsistent (it's less, but for some reason main thread has frames that somtimes seem to wait for worker thread to finish - need to investigate)
Tests: exported snapshot from craggy, unzipped and loaded in perfetto
Bugfix: exclude 'length' bytes from content end offset
Tests: none, trivial change
Update: Add support to export snapshot as a binary blob
- Also emitting compressed version of json and bin snapshots
- Minor code reorganization + TODOs
Surprisingly, despite tighter binary format, it compressed to a larger size than compressed json
Tests: loaded compressed snapshot to perfetto. Didn't trest the binary as it doesn't have any readers yet, so it's untested
Bugfix: patch sheared frames when exporting json snapshot
- In Editor EndOfFrame is called as part of nested GUI, which our profiler shears apart. For now we inject additional marks to maintain callstack structure
- left a TODO to properly reconstruct a sheared frame
- For now expanding frame scope to cover sheared period
Tests: exported craggy snapshot and opened in perfetto - no more randomly trashed frames
Update: Factor out profielr exporting logic to a separate script
- Also cleaned up a couple log outputs, as the collection seems sensible
- Cleaned a couple already-done TODOs
Tests: Did an export from editor and standalone server (6k size, 0 pop), loaded in perfetto
Undo: removing ignore.conf accidental submit
Tests: none
Update: ServerProfiler snapshot now contains full names for scopes
Tests: opened the new profile in perfetto
Update: Emit all 10 frames of snapshot
- Also emitting UnityFrame as a CompleteEvent, so it's always visible in the profiler
- UnityFrames are now numbered
This produces a 160mb snapshot on Craggy (taken immediately after spawning), will need testing on larger worlds (and this is before proper labels)
Tests: opened snapshot in perfetto - saw all 10 frames
Update: Synthesize missing OnEnter profiling marks
This restore the profile's structure
Test: opened snapshot in perfetto
Update: first export of profiling snapshot
- Also filtering out System and System.Core from annotation (otherwise we produce too much data, even for 1 frame)
- Also added timestamp utility functions (as trace format requires micros)
Not super reliable - need to post-process gathered data to get rid of torn marks
Tests: opened trace in perfetto - although wonky, it's there
Update: minor improvements to ServerProfiler
- Added a smidge more debug to track the growth of per-frame lazy storage
- Added output of how long each frame took
Tests: ran the perfsnapshot command
Update: add profile.perfsnapshot command
Currently just outputs gathered marks telemetry for sanity checking - will expand more once happy with results.
Tests: ran the command and confirmed output
Update: more improvements and debug to ServerProfiler
- Added tracking of thread IDs
- Only gather main thread marks (have thread races in my lock-free approach, so delaying this till later)
- Add tracking of assemblies to which the method belongs
- Filter our mscorlib assembly from instrumenting
- rewrote code to use ref semantics
Still chasing why consecurtive snapshots seem to double-up in size on frames 2-10.
Tests: ran a bunch of profile snapshots (next frame) and looked at the output. It works but has above weird behavior.
Bugfix: various ServerProfiler fixes and improvements
- Account that native strings are not null terminated when doing unmanaged string comparison
- Filter out native profiler funcs from annotation
- Unregister profiler callbacks when stopping play in editor (this would cause mono crash on repeat plays due to GCed callbacks)
- Reduce scope of unsafe keyword (as some funcs are safe)
- Replace test-run annotation with fully enabled one
- Hook in on frame end to count frames
Tests: Started, stopped and started the game in the editor. Wrote some simple test code to validate StrEq. Validated in logs that native serverprofiler functionality is ignored.
Update: Filter instrumenting anotations based on class and namespaces
- Added reporting of class and namespace into annotation log
Currently only skipping ServerProfiler itself to avoid a recursion when invoking callbacks (will be tested in next submit).
Tests: pressed play in editor - saw the instrumentation logs
Update: Invoking of profiler method annotation filter works
- Instead of hooking in we rely on Unity's assembly initialization to invoke us first - seems to be early enough, but we'll see
- Store profiler callbacks to avoid GC cleaning them up and crashes in mono
- Add compile guards (for now allowing to run editor to test)
Tests: launched in editor, no crashes and a lot(112k) of debug logs indicating what gets annotated.
Update: skeleton of a server profiler
- Most of the native imports in place
- Implemented the general flow of per-frame tracking
In theory should be able to track function entry/exits, but can't test until a decide on an early enough method of initialization.
Tests: none, too early
Merge: from main
Tests: none (trivial merge)
Merge: from remove_editor_update
- Removes last editor-only update invoke case with many invocations(saves a measly 0.1ms).
- `demo.play` accepts absolute paths
Tests: setup an industrial chain with a chest provider and a crafter and linked those up - debug vizualization worked. Loaded a demo outside of demos folder.
Update: demo.play respects absolute paths
Tests: Tried to play a demo outside of demos folder
Optim: Remove IO pipe debug update invoke
Turns out to save much less than expected (just 0.1ms), but this eliminates last editor-only update invoke with many instances.
Tests: On craggy setup a chest->producer industrial circuit, was able to visualize debug
Merge: from main
Tests: none
Merge: from main
Tests: none(trivial merge)
Merge: from remove_editor_update
Removes around 1.5ms from 6k world in the editor and fixes longstanding bugs with the decal editing.
Tests: Created a bunch of decals, modified their properties(changes visible), deleted them(no NREs), ran in game - still visible.
Merge: from main
Tests: none(trivial merge)
Bugfix: avoid exceptions when modifying decals in editor
Tests: on craggy spawned a bunch of decals, modified them in various ways, deleted them - no exceptions
Optim: Remove editor-only per-decal Update callback
- They've all been consolidated to DeferredDecalRenrerer by tracking Undo history changes
This saves about 1.5ms during Update stage (in reality it's a bit less because of profiling overhead).
Tests: On Craggy ran around and validated I could still see footprints. Spawned them manually and tweaked settings and moved it's placement(ok) - trying to delete placed decal starts an exception loop(pre-existing bug, will fix next)
Merge: from main
Tests: none (trivial merge)
Merge: from vehicle_optims
Saves 0.5ms on a 6k world by avoiding iterating over unmounted mountables
Tests: On craggy drove a kayak. On 6k world confirmed that the profiling scope shrunk to 0
Merge: from main
Tests: none (trivial merge)
Optim: Avoid trying to sync non-mounted mountables
- Implemented via a mounted-queue that gets populated when a vehicle/animal is mounted
This saves 0.5ms on a 6k world map with no players riding vehicles.
Tests: on Craggy rode a kayak and validated player transform sync was happening via profiler. Loaded 6k world and validated that the original 1.3k item queue was gone.
Update: Reducing access to BaseMountable internal state
- Mods can workaround by using existing API
Future optim depends on internal state being tightly controlled, so this makes it easier to prove that it'll be safe.
Tests: rode the zipline on craggy
Merge: from profiling_improvements
Removes boxing allocations in Pool.Get and Pool.Free in Editor context.
Tests: in editor on Craggy started a normal session, couldn't see allocations in the profiler. Overrode the startup params and was able to see the overhead table printed out when invoking cmd.
Merge: from main
Tests: none
Update: Make Pool capacity waste tracking off by default
- Added an editor-only command to enable it, "pool.memory_overhead_tracking_enabled"
- Cleaned up implementation a smidge, left a comment explaining where the box is coming from
- "pool.print_memory_overhead" skips entries with 0 overhead
I couldn't find a way to avoid boxing in a generic call, so I decided to disable this telemetry gathering by default to avoid muddying profiler data.
Tests: in editor on Craggy started a normal session, couldn't see allocations in the profiler. Overrode the startup params and was able to see the overhead table printed out when invoking cmd.
Merge: from main
Tests: none
Update: changing starting scene to be Bootstrap when running a perf test
- Also removed direct world setup settings modification, instead pushing them to global World static params
We have to go via Bootstrap because that's what initializes global systems. Will need to massage platform-specific transition logic to account for perf testing workflow (need to support CLIENT+SERVER flow).
Tests: Test player fails because of CWD, but if I run TestPlayer manually it boots and loads to main menu, so I count it as pass-ish
Update: Symlink assetbundles on test player build
Tests: ran the test, validated that they got symlinked to expected path (but there are other issues, investigating)
Update: Sneak in console cmds via command line
Need a better way in the future, but for now this should allow to control test conditions.
Tests: none (need to fix assetbundle copying first), though validated it sohuld work by reading through code
Merge: from main
Tests: none
Merge: from main
Tests: none
Merge: from profiling_improvements
Just additional profiling annotations to fill in voids on FixedUpdate and UpdateLOD. Also editor microoptim in GamePhysics.
Tests: Rode a horse on Craggy and checked profiler for changes
