Auto Watch: time other mods' patches on hot methods within the 40-method cap (stacked on #2)

CLAUDE.md

@@ -27,13 +27,14 @@ source/Core/     Pure C# (netstandard2.1), no Unity or Timberborn types: this is
   Profile.cs     Keyed profile (singletons, entity kinds, components, watched methods): exact and sampled timing, budgeted sampling, spike attribution.
   LogWriter.cs   One thread that writes every file (tables from rings, an events queue, files rewritten whole). Never blocks the game thread.
   Summary.cs     summary.md (pure formatting). Header.cs: header lines, and README.md / columns.md text. PatchReport.cs: which mod patches which hot method.
+  AutoWatch.cs   Which of other mods' patch methods the auto watch (AutoWatch = true) times, in the free Watch slots.
   Alloc/Cpu/Milestones/Ring.cs   Small sources.
 source/Game/     The Timberborn side (needs the game's assemblies to compile).
   Plugin.cs      IModStarter, and the Bindito configurators. Reads config, installs patches.
   SessionService Bindito singleton: PostLoad starts a Session, Unload stops it.
   Session.cs     One log from load to unload: folders, header, writer, probe start/stop, summary refresh, events.
   Instrumentation.cs   The Harmony patch list (CreateSpecs) and every patch body. Wrappers.cs: timing wrappers put into the game's singleton arrays, LoadRecorder, SaveTracker.
-  Watch.cs       Config-driven method timing. PlayerLoopTiming.cs: Unity phase markers and the frame boundary. UnityExtras.cs: profiler counters, frame timing.
+  Watch.cs       Config-driven method timing, and the auto watch's patches on other mods' patch methods. PlayerLoopTiming.cs: Unity phase markers and the frame boundary. UnityExtras.cs: profiler counters, frame timing.
   Environment.cs Computer/game facts, mod list, assembly-to-mod map, Harmony patch reader. Config.cs: PerformanceLog.cfg.
   Settings.cs    The in-game settings page (the Mod Settings mod). The only file that touches ModSettings.Core/.Common types.
 tests/           .NET 8 console checks (no test framework). Core checks run for real; game checks run against the installed game's real assemblies.
@@ -99,12 +100,22 @@ To read the game's own code (the way every patch target here was checked): `ilsp
   (`ProfileTests.NoAliasing`).
 - **`Columns` is initialised in textual order** (C# static field initialisers). Declare arrays before the groups that use them.
 - **Only some settings can live in the in-game Mod Settings menu** (`Settings.cs`, `PerformanceSettings`). `Plugin.StartMod` reads `PerformanceLog.cfg`
-  and decides `Enabled`/`Profile`/`Watch` (which Harmony patches get made, including whether the entity tick is patched at all) before Bindito, and so
+  and decides `Enabled`/`Profile`/`Watch`/`AutoWatch` (which Harmony patches get made, including whether the entity tick is patched at all) before Bindito, and so
   Mod Settings, exists; making those live would mean re-patching the game while it runs or always paying for the entity-tick patch even when `Profile = off`
   asks not to. Only the six numbers `Session.Start` reads fresh each session (`SlowFrameMs`, `SummarySeconds`, `ProfileSeconds`, `OverheadBudgetPercent`,
   `SpikeContributors`, `MaxSlowRowsPerMinute`) are in the menu; `SessionService.PostLoad` calls `PerformanceSettings.ApplyTo` to fold them onto `Plugin.Config`
   before each `Session.Start`. A `ModSetting<T>`'s `.Value` is `default(T)` until Mod Settings calls `Load()` (which needs a real `ISettings`/`ModRepository`);
   what this mod controls at construction, and what `Load()` seeds `.Value` from the first time, is `.DefaultValue` — tests read that, not `.Value`.
+- **The auto watch is the one patching done after `StartMod`** (`Watch.AutoInstall`, from `Session.Start` when `AutoWatch = true`): once per run of the
+  game, when the first log starts, because only then are other mods' patches (made at their start and while the game loads) in Harmony's registry, and
+  nothing ticks yet. It only adds this mod's own prefix and postfix (id `kyler.performancelog.watch`) around another mod's patch method; it never unpatches,
+  reorders or changes anyone else's patch. Which methods it takes is decided in `AutoWatch.Plan` (pure, tested in `AutoWatchTests`): name order, not time,
+  because ranking by what the recording measured would mean patching while the game runs.
+- **Under BeaverBuddies, making a Harmony patch draws from the game's random numbers.** Every `Harmony.Patch` builds a MonoMod `DynamicMethodDefinition`,
+  which calls `Guid.NewGuid()`, and BeaverBuddies' `GuidPatcher` turns each `Guid.NewGuid()` into 16 draws from `UnityEngine.Random`, the state the
+  simulation's `RandomNumberGenerator` uses and that BeaverBuddies seeds when a game loads. Patching at `StartMod` is harmless (the seed comes later);
+  any patch made after a game has started loading must run inside `Watch.KeepUnityRandom` (which puts `UnityEngine.Random.state` back as it was), or
+  one player's random numbers move and co-op desyncs. Never patch mid-game, not even with that guard (it is only proven at load, before the first tick).
 - Colony and memory columns are read only when a row is written and carried over otherwise (`lastHeavy` in `Probe`).
 - The tests run each check on a thread-pool thread, and `Probe` is static and remembers the game thread's id: every check that uses it goes through `Rig` in `CoreTests.cs`.
 

README.md

@@ -68,7 +68,8 @@ front, and change one thing.
 - **What each measurement source could do** and whether it actually produced anything, so a zero is never mistaken for a measurement.
 - **What measuring itself costs**, per frame, in the file.
 
-Any method can also be timed by name (`Watch` in the config). See the file.
+Any method can also be timed by name (`Watch` in the config), and with `AutoWatch = true` so can the patch methods other mods put on the game's
+hot methods, each on its own row. See the file.
 
 ## Settings
 
@@ -78,7 +79,7 @@ rather than a rough scale-up. This costs a bit more than a lighter profile — s
 ever matters more than the detail.
 
 Six of the settings can be changed from Timberborn's **Mod Settings** menu, with no restart: they take effect from the next game or save you load.
-The rest — `Enabled`, `Profile`, `Watch` and `OutputFolder` — decide which parts of the game get patched, which is settled before that menu exists,
+The rest — `Enabled`, `Profile`, `Watch`, `AutoWatch` and `OutputFolder` — decide which parts of the game get patched, which is settled before that menu exists,
 so they live only in `PerformanceLog.cfg` (next to `manifest.json` in the mod's `version-1.1` folder) and need the game restarted after editing.
 Nothing here changes what the game simulates, so co-op players may use different values.
 
@@ -94,6 +95,7 @@ Nothing here changes what the game simulates, so co-op players may use different
 | `MaxSlowRowsPerMinute` | `300` | .cfg or Mod Settings | At most this many slow frames get a row a minute; the rest are only counted, so a game that is slow all the time cannot fill the disk. |
 | `OutputFolder` | *(empty)* | .cfg only | Where session folders go. Empty = `Documents\Timberborn\PerformanceLog`. |
 | `Watch` | *(none)* | .cfg only | Full names of methods to time: `Namespace.Type.Method`, separated by `;`, on as many lines as you like (at most 40 methods; every overload of a name is watched). Rows appear in `profile.csv` as kind `method`. |
+| `AutoWatch` | `false` | .cfg only | `true` = also time the patch methods other mods put on the game's hot methods, in the Watch slots the `Watch` entries leave (40 in all). See below. |
 
 The first time you open the Mod Settings page it starts from whatever `PerformanceLog.cfg` already says; after that, whatever you set there is what
 is used, and editing that number in the file no longer does anything (Mod Settings remembers it, not this mod).
@@ -109,12 +111,33 @@ method that runs thousands of times a tick costs more than watching a rare one.
 (Harmony cannot patch them under Mono and the attempt can crash the game). A `# watch|` line in the `frames.csv` header, and the "What each measurement source
 could do" section of `summary.md`, say for each name whether it is being watched or why not.
 
+**`AutoWatch = true`** does this for the patches other mods put on the game's hot methods, without naming them. A mod's prefix on every entity's tick
+(BeaverBuddies has one) or on a singleton's `Tick` (Late Game Performance has several) runs inside a row that names the game or the singleton, so its cost
+is otherwise invisible. When the first game is loaded, the mod reads Harmony's list of patches and times other mods' prefixes, postfixes and finalizers:
+first those on the per-tick and per-frame methods behind the profile's own rows (a singleton's `Tick`, `UpdateSingleton`, `LateUpdateSingleton` or
+`StartParallelTick`, an entity's or a component's `Tick`), then those on the rest of the hot methods the header lists, in name order, in the slots the
+`Watch` entries leave free (40 methods in all; your `Watch` entries always come first). Patches on the game's random numbers, `Guid.NewGuid` and
+`DateTime.ToString` are left out (BeaverBuddies' co-op code, called very often); a `Watch` entry can still name one. Each gets a `method` row in `profile.csv`, named after the patch
+method and tagged with its mod, and a `# watch|...|auto|...` line in the `frames.csv` header saying which hot method it is on; the ones left out say why.
+It only adds its own timing patch around each patch method: no other mod's patch is removed, reordered or changed. It is off by default because every
+call of a watched method pays for the watch, and some of these run tens of thousands of times a second or more; compare `overheadUs` with it on and off. A
+patch another mod makes after the game has loaded is not seen, and a very small patch method may have been copied into the method it patches by the
+runtime, where no watch can see it (`# capability-final|autoWatch|` lists any that were never seen called). A prefix marked `(can replace it)` may skip
+the game's method and do its work itself, so its time is that work done instead of the game's, not on top of it.
+
+With BeaverBuddies, making any Harmony patch uses up some of the game's random numbers (BeaverBuddies makes `Guid.NewGuid` draw from them, and Harmony
+calls it for every patch), and the auto watch patches after the game has been seeded for co-op. It therefore puts the random state back exactly as it
+was once its patches are made, so the game plays out the same with it on or off and co-op players may still set it differently. That is reasoned from
+the code and not yet seen in a two-player game (`docs/TESTING.md`, item 10).
+
 ## Working with other mods
 
 The mod puts a timing wrapper in front of each of the game's singletons. It does this only on the first tick and first frame of a game, after every other mod's
 `Load` patches have run. So a mod that looks at those singletons (BeaverBuddies reorders the once-per-tick ones by their type) still sees the game's own, and the
 tick order is what it would be without this mod. It never replaces a game method and never skips the original. When another mod defers the game's save to the
 end of a tick (BeaverBuddies does), the `queued save` event reads about 0 ms and the real one is the `save (writing the world)` event.
+With `AutoWatch = true` it also puts its own timing prefix and postfix (Harmony id `kyler.performancelog.watch`) around other mods' patch methods
+on hot methods, when the first game loads; the other mods' patches, and the order they run in, stay as they were.
 
 ## What it costs, and what it cannot see
 

docs/SESSION-README.md

@@ -94,6 +94,18 @@ Start by writing down what the complaint is, because the causes differ:
   nothing timed was running). An event posted while the game loads waits for `EventBus`'s `post-load` step, so its `[OnEvent]` handlers are charged
   there. The `# patch|other|` and `# patch|shared|` lines name these handlers in full; a `Watch` entry with that name times one, with every patch on it
   (kind `method`).
+- With `AutoWatch = true` in the config (the `# capability|autoWatch|` line says whether it was on and what it did), the patch methods other mods put on
+  hot methods are timed themselves: a `method` row each, named after the patch method (its class says what it is for, e.g.
+  `...TickableEntityTickPatcher.Prefix(TickableEntity)`, and `mod` is the mod that patches), and a `# watch|<method>|watching|auto|<prefix on
+  Namespace.Type.Method>|<owner>` line each in the header. It takes the patches on the methods behind the profile's own rows first (a singleton's
+  `Tick`, `UpdateSingleton`, `LateUpdateSingleton` or `StartParallelTick`, an entity's or component's `Tick`, whose time is otherwise inside a row that
+  names the game or the singleton's own mod), then the rest of the hot methods, in name order, in the Watch slots the config's `Watch` entries left
+  (40 in all), leaving out patches on the random numbers, `Guid.NewGuid` and `DateTime.ToString`; the `# watch|` lines of the ones left out say why. A patch method's time is inside the row of what it patches, so do not add the two.
+  One that `# capability-final|autoWatch|` lists as never seen called was either not called, called only off the game thread (the watch times the game
+  thread only), or so small that the runtime copied it into the method it patches, where no watch can see it: a missing row there is not a measurement of 0.
+  A `# watch|` line that says `(can replace it)` is a prefix that returns a bool: when it returns false the game's own method does not run, and the
+  prefix's row holds the work it did instead, so that time is the mod doing the game's job, not cost on top of it (compare a recording without that
+  mod to see what it saves or costs in all). A prefix that replaces a tick loop (`TickableBucketService.TickBuckets`, say) holds nearly the whole tick.
 - To be sure it is a mod, **compare two recordings** of the same save at the same speed with and without it:
   `python tools/perflog.py compare <folder A> <folder B>` (in the Performance Log repository). Say what else differed.
 

docs/TESTING.md

@@ -6,7 +6,7 @@ since. A 0.1.3 recording (below) shows the `deep` default working, and every 0.1
 
 ## Verified by the automated checks
 
-`dotnet run --project tests -c Release` (106 checks) and `python -m unittest discover -s tools -p "test_perflog.py"` (62 checks).
+`dotnet run --project tests -c Release` (113 checks) and `python -m unittest discover -s tools -p "test_perflog.py"` (65 checks).
 
 | What | How |
 |---|---|
@@ -27,6 +27,7 @@ since. A 0.1.3 recording (below) shows the `deep` default working, and every 0.1
 | The resolver the game side installs names a mod's DLL, `game` for the game's own and leaves the rest unknown; loading steps carry the heap growth | `ProfileTests` |
 | Profile = off leaves the entity tick unpatched; an abandoned save does not block the next; the parallel tick figure is not counted twice; slow-frame rows are limited per minute; the summary is made on the writer thread | `GameBindingTests`, `CoreTests`, `WriterTests` |
 | The config file, the watch list resolution against the real game types | `GameBindingTests` |
+| The auto watch (`AutoWatch = true`): only other mods' prefixes, postfixes and finalizers on the methods behind the profile's rows or on the hot list are taken, in name order whatever order Harmony lists them in, one watch per patch method; never more than the slots the Watch entries left, a Watch entry's method is not watched twice, and a refused or failed patch takes no slot; a patch is examined (label, exception filter, generic) the way a Watch entry is, against real methods; a watched patch method is counted, timed and named in `profile.csv`, and its watch allocates nothing; a prefix that can skip the method it patches is marked `(can replace it)`; the header's `# watch|` and `# capability|autoWatch|` lines and the end's never-called list; every patch is made, and Harmony's registry read, inside `Watch.KeepUnityRandom`, which reads `UnityEngine.Random.state` before and writes it back in a `finally` (checked in its IL; Unity itself cannot run here); the report, `compare` and `summary.md` name each by its class, and `compare` does not count a method only one side watched as extra time | `AutoWatchTests`, `SummaryTests`, `test_perflog` |
 | The analysis tool reads what the mod writes (fixtures come from the real writer) and each finding fires on its situation and not on a healthy one | `tools/test_perflog.py`, `WriterTests.FixturesAreCurrent` |
 | The in-game settings panel's values are clamped onto a `Config` the same way `PerformanceLog.cfg` is, only the six settings that can be, and the panel starts from what the .cfg file already had | `GameBindingTests.SettingsApplyTo`, `SettingsSeedFromTheCfgFile` |
 | A fresh `Config` (nothing set) is `Profile = deep`, `SpikeContributors = 8` and `OverheadBudgetPercent = 1`; a bad or missing `Profile` line falls back to `deep`, not `standard` | `GameBindingTests.ConfigParsing`, `ConfigProblems` |
@@ -113,6 +114,20 @@ What it shows, and the line that shows it:
    `ISettings`/`ModRepository`/`ModSettingsOwnerRegistry` is verified in the game, above.)
 8. **Entity rows keyed by kind (not yet played)**: every entity name in the recordings made up to 0.1.3 was `<template>(Clone)` or `<template> <a beaver's name>`,
    and the checks cover both; that a new recording from a loaded save has one row per kind is step 7 below.
+9. **`AutoWatch = true` (not yet played)**: Harmony cannot apply a patch in the test process, so that the auto watch's patches on other mods' patch methods
+   are made, and that Harmony hands them the method the watch looks up, is only reasoned, not seen. Set `AutoWatch = true` in `PerformanceLog.cfg`, restart,
+   load a save with BeaverBuddies (or any mod that patches `TickableEntity.Tick`) and play 3 minutes. Check that `Player.log` says `Auto watch: watching N of M
+   patch methods...` with N > 0 and no warning, that the `frames.csv` header has `# capability|autoWatch|watching ...` and a `# watch|...|watching|auto|...`
+   line per method, that `profile.csv` has `method` rows for them (BeaverBuddies' `TickableEntityTickPatcher.Prefix` should be one of the busiest), that
+   `# capability-final|autoWatch|` says most of them were called, and what `overheadUs` costs compared with the same save with `AutoWatch = false`. A patch
+   method listed there as never seen called is either not called, called only off the game thread, or inlined by the runtime into the method it patches,
+   which no watch can see. A row whose `# watch|` line says `(can replace it)` is a prefix that may skip the game's method and do the work itself.
+
+10. **`AutoWatch` in co-op (not yet played)**: under BeaverBuddies every Harmony patch draws from the game's random numbers (MonoMod's
+    `DynamicMethodDefinition` calls `Guid.NewGuid`, which BeaverBuddies routes through `UnityEngine.Random`), and the auto watch patches after BeaverBuddies
+    has seeded them for the game. `Watch.KeepUnityRandom` puts the state back, so the game should play out the same; that is reasoned from the code, not seen.
+    Play two players connected with BeaverBuddies for 10 minutes or more, with `AutoWatch = true` for one player only (the case a difference would show
+    first), some of it at speed 3 or more, including a save: there must be no desync, and BeaverBuddies' own behaviour and `Player.log` must be as without it.
 
 ## Five-minute check in a game