diff --git a/Assets/Tests/Editor/HotReload/HotReloadCompilationAssemblyReconstructionTests.cs b/Assets/Tests/Editor/HotReload/HotReloadCompilationAssemblyReconstructionTests.cs
index 3b258a9de..11a442efd 100644
--- a/Assets/Tests/Editor/HotReload/HotReloadCompilationAssemblyReconstructionTests.cs
+++ b/Assets/Tests/Editor/HotReload/HotReloadCompilationAssemblyReconstructionTests.cs
@@ -5,6 +5,7 @@
using System.Threading.Tasks;
using Newtonsoft.Json;
+using Newtonsoft.Json.Linq;
using NUnit.Framework;
@@ -402,6 +403,132 @@ public void ReconstructAndFill_WhileCompilationFailed_KeepsAndSavesNothing()
Is.EqualTo(HotReloadConstants.CompilationListReasonCompilationFailed));
}
+ ///
+ /// What: a rebuild that fills the cache logs both the background time and the main thread
+ /// wait, and together they fit within the whole time.
+ ///
+ [Test]
+ public void ReconstructAndFill_WhenFilled_LogsTheBackgroundAndMainThreadWaitTimes()
+ {
+ HotReloadCompilationAssemblyListStore store = SaveCleanThenEdit(saved => { });
+ HotReloadCompilationAssemblyCache cache = new HotReloadCompilationAssemblyCache(Array.Empty);
+ VibeLogger.ClearMemoryLogs();
+
+ Task refill = CreateRefill(store, cache).RunAsync();
+
+ Assert.That(refill.Status, Is.EqualTo(TaskStatus.RanToCompletion), "refill status");
+ JObject context = HotReloadWarmUpTestDoubles.ReadSingleVibeContext(HotReloadConstants.VibeLogCompilationListReconstructed);
+ Assert.That((bool)context["filled"], Is.True, "filled");
+ Assert.That(context["backgroundMs"].Type, Is.EqualTo(JTokenType.Integer), "backgroundMs");
+ Assert.That(context["mainThreadWaitMs"].Type, Is.EqualTo(JTokenType.Integer), "mainThreadWaitMs");
+ long backgroundMs = (long)context["backgroundMs"];
+ long mainThreadWaitMs = (long)context["mainThreadWaitMs"];
+ Assert.That(backgroundMs, Is.GreaterThanOrEqualTo(0), "backgroundMs");
+ Assert.That(mainThreadWaitMs, Is.GreaterThanOrEqualTo(0), "mainThreadWaitMs");
+ Assert.That(backgroundMs + mainThreadWaitMs, Is.LessThanOrEqualTo((long)context["reconstructMs"]), "sum");
+ }
+
+ ///
+ /// What: a rebuild cancelled after the background work finished logs the background time and
+ /// leaves the main thread wait null, because the switch to the main thread never completed.
+ ///
+ [Test]
+ public async Task ReconstructAndFill_CancelledBeforeTheMainThread_LogsOnlyTheBackgroundTime()
+ {
+ HotReloadCompilationAssemblyListStore store = SaveCleanThenEdit(saved => { });
+ HotReloadCompilationAssemblyCache cache = new HotReloadCompilationAssemblyCache(Array.Empty);
+ TaskCompletionSource held =
+ new TaskCompletionSource();
+ Func rebuild = null;
+ HotReloadCompilationListRefill refill = new HotReloadCompilationListRefill(
+ store,
+ cache,
+ HotReloadSnapshotCaptureInputs.ReadOnMainThread,
+ () => _isCompilationFailed,
+ work =>
+ {
+ rebuild = work;
+ return held.Task;
+ });
+ VibeLogger.ClearMemoryLogs();
+
+ Task run = refill.RunAsync();
+ HotReloadCompilationListReconstruction rebuilt = rebuild();
+ refill.Cancel();
+ held.SetResult(rebuilt);
+ // Why awaited: the rest of the run resumes off this thread after the held rebuild completes.
+ await run;
+
+ JObject context = HotReloadWarmUpTestDoubles.ReadSingleVibeContext(HotReloadConstants.VibeLogCompilationListReconstructed);
+ Assert.That((string)context["reason"], Is.EqualTo(HotReloadConstants.CompilationListReasonCancelled), "reason");
+ Assert.That(context["backgroundMs"].Type, Is.EqualTo(JTokenType.Integer), "backgroundMs");
+ Assert.That(context["mainThreadWaitMs"].Type, Is.EqualTo(JTokenType.Null), "mainThreadWaitMs");
+ }
+
+ ///
+ /// What: a rebuild cancelled while the background work runs logs neither time as a number,
+ /// because the work threw before its time was taken.
+ ///
+ [Test]
+ public async Task ReconstructAndFill_CancelledDuringTheRebuild_LogsNeitherTime()
+ {
+ HotReloadCompilationAssemblyListStore store = SaveCleanThenEdit(saved => { });
+ HotReloadCompilationAssemblyCache cache = new HotReloadCompilationAssemblyCache(Array.Empty);
+ TaskCompletionSource held =
+ new TaskCompletionSource();
+ Func rebuild = null;
+ HotReloadCompilationListRefill refill = new HotReloadCompilationListRefill(
+ store,
+ cache,
+ HotReloadSnapshotCaptureInputs.ReadOnMainThread,
+ () => _isCompilationFailed,
+ work =>
+ {
+ rebuild = work;
+ return held.Task;
+ });
+ VibeLogger.ClearMemoryLogs();
+
+ Task run = refill.RunAsync();
+ refill.Cancel();
+ OperationCanceledException thrown = Assert.Throws(() => rebuild());
+ held.SetException(thrown);
+ // Why awaited: the rest of the run resumes off this thread after the held rebuild completes.
+ await run;
+
+ JObject context = HotReloadWarmUpTestDoubles.ReadSingleVibeContext(HotReloadConstants.VibeLogCompilationListReconstructed);
+ Assert.That((string)context["reason"], Is.EqualTo(HotReloadConstants.CompilationListReasonCancelled), "reason");
+ Assert.That(context["backgroundMs"].Type, Is.EqualTo(JTokenType.Null), "backgroundMs");
+ Assert.That(context["mainThreadWaitMs"].Type, Is.EqualTo(JTokenType.Null), "mainThreadWaitMs");
+ }
+
+ ///
+ /// What: a rebuild whose background work does not finish logs neither time as a number, so a
+ /// step that never ran is not reported as taking 0 ms.
+ ///
+ [Test]
+ public void ReconstructAndFill_WhenTheRebuildFails_LogsNeitherTime()
+ {
+ HotReloadCompilationAssemblyListStore store = SaveCleanThenEdit(saved => { });
+ HotReloadCompilationAssemblyCache cache = new HotReloadCompilationAssemblyCache(Array.Empty);
+ HotReloadCompilationListRefill refill = new HotReloadCompilationListRefill(
+ store,
+ cache,
+ HotReloadSnapshotCaptureInputs.ReadOnMainThread,
+ () => _isCompilationFailed,
+ work => Task.FromException(new InvalidOperationException("test")));
+ VibeLogger.ClearMemoryLogs();
+
+ Task run = refill.RunAsync();
+
+ Assert.That(run.Status, Is.EqualTo(TaskStatus.RanToCompletion), "refill status");
+ Assert.That(run.Result, Is.False, "kept");
+ JObject context = HotReloadWarmUpTestDoubles.ReadSingleVibeContext(HotReloadConstants.VibeLogCompilationListReconstructed);
+ Assert.That((string)context["reason"], Is.EqualTo(nameof(InvalidOperationException)), "reason");
+ Assert.That(context["backgroundMs"].Type, Is.EqualTo(JTokenType.Null), "backgroundMs");
+ Assert.That(context["mainThreadWaitMs"].Type, Is.EqualTo(JTokenType.Null), "mainThreadWaitMs");
+ }
+
private void AssertRecompiledTargetGives(string reason, Action editTargetReference)
{
HotReloadCompilationAssemblyListStore store = SaveCleanThenEdit(saved =>
diff --git a/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationAssemblies.cs b/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationAssemblies.cs
index cb03b5b66..b429246ca 100644
--- a/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationAssemblies.cs
+++ b/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationAssemblies.cs
@@ -12,12 +12,14 @@
namespace io.github.hatayama.UnityCliLoop.FirstPartyTools
{
///
- /// The compilation assembly list for hot reload, asked of Unity once per domain.
+ /// The compilation assembly list for hot reload, kept for the rest of the domain.
/// Why: on a project with several hundred assemblies one CompilationPipeline.GetAssemblies() call
/// takes 340-620 ms, while the list only changes through a compile, or through an import that
/// changes the script set without compiling (see HotReloadCompilationAssemblyListPostprocessor).
- /// Whichever caller first needs the list after a domain reload asks Unity for it; later callers
- /// in the domain find it kept.
+ /// After a domain reload the list is normally rebuilt on a pool thread from the list a previous
+ /// domain saved (RefillInBackground). Unity is asked only when that rebuild kept nothing or the
+ /// list was dropped in the domain, by the first caller that then needs it; later callers in the
+ /// domain find it kept.
/// A list rebuilt at startup from the saved list holds only the fields hot reload reads: name,
/// outputPath, sourceFiles, defines, assemblyReferences and compiledAssemblyReferences.
/// compilerOptions, flags and rootNamespace keep their defaults, so code that needs them reads
diff --git a/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationListRefill.cs b/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationListRefill.cs
index c792b330c..33e657c47 100644
--- a/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationListRefill.cs
+++ b/Packages/src/Editor/FirstPartyTools/HotReload/Shared/HotReloadCompilationListRefill.cs
@@ -69,21 +69,31 @@ internal void Cancel()
private async Task RunUntilCancelledAsync(CancellationToken ct)
{
Stopwatch watch = Stopwatch.StartNew();
+ long? backgroundMs = null;
+ long? mainThreadWaitMs = null;
try
{
int generation = _cache.Generation;
HotReloadSnapshotCaptureInputs inputs = _readInputs();
- HotReloadCompilationListReconstruction reconstruction = await _runInBackground(
- () => HotReloadCompilationAssemblyReconstruction.Reconstruct(_store, inputs, ct)).ConfigureAwait(false);
+ HotReloadCompilationListReconstruction reconstruction = await _runInBackground(() =>
+ {
+ // Why measured inside the work: the time it waited for a pool thread is not rebuilding.
+ Stopwatch backgroundWatch = Stopwatch.StartNew();
+ HotReloadCompilationListReconstruction rebuilt = HotReloadCompilationAssemblyReconstruction.Reconstruct(_store, inputs, ct);
+ backgroundMs = backgroundWatch.ElapsedMilliseconds;
+ return rebuilt;
+ }).ConfigureAwait(false);
// Why the main thread: the cache has no lock and is kept on the main thread only.
+ Stopwatch waitWatch = Stopwatch.StartNew();
await MainThreadSwitcher.SwitchToMainThread(ct);
+ mainThreadWaitMs = waitWatch.ElapsedMilliseconds;
// Why not kept after a failed compile: the dlls are then older than the sources, so
// every stamp still matches the saved list while Unity's list already names the
// added and removed files.
if (reconstruction.Assemblies != null && _isCompilationFailed())
{
- LogReconstructed(false, HotReloadConstants.CompilationListReasonCompilationFailed, watch.ElapsedMilliseconds);
+ LogReconstructed(false, HotReloadConstants.CompilationListReasonCompilationFailed, watch.ElapsedMilliseconds, backgroundMs, mainThreadWaitMs);
return false;
}
@@ -98,12 +108,12 @@ private async Task RunUntilCancelledAsync(CancellationToken ct)
string reason = filled
? null
: reconstruction.FailureReason ?? HotReloadConstants.CompilationListReasonSuperseded;
- LogReconstructed(filled, reason, watch.ElapsedMilliseconds);
+ LogReconstructed(filled, reason, watch.ElapsedMilliseconds, backgroundMs, mainThreadWaitMs);
return filled;
}
catch (OperationCanceledException) when (ct.IsCancellationRequested)
{
- LogReconstructed(false, HotReloadConstants.CompilationListReasonCancelled, watch.ElapsedMilliseconds);
+ LogReconstructed(false, HotReloadConstants.CompilationListReasonCancelled, watch.ElapsedMilliseconds, backgroundMs, mainThreadWaitMs);
return false;
}
catch (Exception ex)
@@ -111,17 +121,18 @@ private async Task RunUntilCancelledAsync(CancellationToken ct)
// Approved deviation: this is the boundary of work that started at Editor startup,
// and a list that cannot be rebuilt only leaves the cache to ask Unity as before.
string reason = ex.GetType().Name;
- LogReconstructed(false, reason, watch.ElapsedMilliseconds);
+ LogReconstructed(false, reason, watch.ElapsedMilliseconds, backgroundMs, mainThreadWaitMs);
return false;
}
}
- private static void LogReconstructed(bool filled, string reason, long reconstructMs)
+ // backgroundMs and mainThreadWaitMs stay null when the run did not get through that step.
+ private static void LogReconstructed(bool filled, string reason, long reconstructMs, long? backgroundMs, long? mainThreadWaitMs)
{
VibeLogger.LogInfo(
HotReloadConstants.VibeLogCompilationListReconstructed,
"Hot reload rebuilt the compilation assembly list at startup.",
- new { filled, reason, reconstructMs });
+ new { filled, reason, reconstructMs, backgroundMs, mainThreadWaitMs });
}
}
}
diff --git a/docs/vibe-logs.md b/docs/vibe-logs.md
index 9e1bdb384..25e7caf46 100644
--- a/docs/vibe-logs.md
+++ b/docs/vibe-logs.md
@@ -155,9 +155,51 @@ command ran against:
The phases add up to `totalMs` except for the loop overhead; `captureMs` in the captured entry
also includes reading the compile start and the package roots, and writing this breakdown entry.
`hot_reload_compilation_assemblies_fetched` appears each time hot reload asks Unity for the
- compilation assembly list, with `fetchMs` and `assemblyCount`. The list is kept for the rest of
- the domain once it is not empty, so this normally appears once per domain, from whichever of the
- warm-up or the first hot reload run needs the list first.
+ compilation assembly list, with `fetchMs` and `assemblyCount`. After a domain reload the list is
+ normally rebuilt off the main thread from the list a previous domain saved
+ (`hot_reload_compilation_list_reconstructed` below), so this appears only when that rebuild kept
+ no list or the cache was invalidated in the domain, from the first hot reload run that needs the
+ list. The list is then kept for the rest of the domain once it is not empty.
+ `hot_reload_compilation_list_reconstructed` appears once per domain reload. `filled` says whether
+ the rebuilt list filled the cache, and `reason` says why it did not:
+ - `no_saved_list`: no list has been saved yet.
+ - `saved_list_unreadable`: the saved list is torn, of another format version, or missing a
+ required field.
+ - `assembly_set_changed`: an assembly definition was added or removed after the list was saved.
+ - `pdb_mismatch`: the PDB beside a compiled-again dll belongs to another build, as while a
+ compile replaces the files.
+ - `pdb_documents_incomplete`: neither the PDB of a compiled-again assembly nor the compiler's
+ own PDB of the same build shows that it names every source the compile was given.
+ - `unresolved_reference`: a reference has a file name the saved list does not know, or a project
+ reference is not in the list.
+ - `reference_missing`: every path saved for a reference's file name is gone, as when a package
+ update renames its folder.
+ - `reference_changed`: a saved path exists, but not with the dll of the recorded MVID.
+ - `compilation_failed`: the last compile failed, so the dlls are older than the sources.
+ - `superseded`: the cache was filled or invalidated meanwhile.
+ - `cancelled`: a compile started or the domain is ending.
+ - `tool_disabled`: the hot-reload tool is disabled in the tool settings.
+ - Any other value is the type name of the exception that stopped the rebuild.
+ `reconstructMs` is the time from the start of the rebuild to the entry, including the wait for
+ the main thread. `backgroundMs` is the time spent rebuilding on a pool thread, without the wait
+ for that thread, and `mainThreadWaitMs` the time it then waited for the main thread to run again.
+ Either is null when the rebuild did not get through that step. A `tool_disabled` entry has only
+ `filled` and `reason`, because no rebuild started.
+ When the cache was not filled, the first hot reload run that needs the list asks Unity for it
+ (`hot_reload_compilation_assemblies_fetched`) and saves it when the cache was not invalidated
+ in the domain and the last compile did not fail, so a reason that comes from an old saved list
+ (`no_saved_list`, `saved_list_unreadable`, `assembly_set_changed`, `unresolved_reference`,
+ `reference_missing`, `reference_changed`) does not repeat after that. Without a list, the
+ warm-up skips `publicized_targets`, `referenced_method_sets` and `transform_worker` with
+ `compilation_list_unavailable`.
+ `hot_reload_compilation_list_saved` appears when a list was written for the next domain, with
+ its size in `bytes`, `saveMs`, and the counts of `assemblies` and `references`. It is written on
+ a pool thread after a list is asked of Unity and after a rebuilt list fills the cache, only when
+ the cache was not invalidated in the domain and the last compile did not fail.
+ `hot_reload_compilation_list_save_skipped` names why a list was not saved in `reason`:
+ `generation` (the cache was invalidated in the domain), `compilation_failed`, or `superseded`
+ (the cache was invalidated while it was written, as when a compile started).
+ `hot_reload_compilation_list_save_failed` is a warning with the exception type name in `error`.
After a domain reload, the warm-up writes one `hot_reload_warm_up_complete` with the target
assemblies, each item's `outcome` (`done`, `cancelled` or `failed`) and time, and `cancelledBy`
(`run`, `beforeAssemblyReload`, `compilationStarted`, or null), or one