Measure task host overhead in mt

[OvesN]

Fixes #13372

Context

In multi-threaded (MT) mode, tasks that are not marked with [MSBuildMultiThreadableTask] are routed to an out-of-proc task host process for isolation. This introduces overhead from IPC serialization, process communication, environment setup, assembly loading, and parameter marshaling - all on top of the actual task execution time.

This PR uses ETW instrumentation to measure that overhead and provides tooling to analyze the results.

Changes Made

Added ETW events to MSBuildEventSource (events 109–112)

Event ID	Name	Location	What it measures
109	TaskHostDispatchStart	TaskHostTask.Execute() (main process)	Start of full task host roundtrip
110	TaskHostDispatchStop	TaskHostTask.Execute() (main process)	End of full roundtrip (includes IPC + remote execution)
111	TaskExecuteInHostStart	OutOfProcTaskAppDomainWrapperBase (task host process)	Start of actual task.Execute()
112	TaskExecuteInHostStop	OutOfProcTaskAppDomainWrapperBase (task host process)	End of actual task.Execute()

How the events map to the execution flow

Main process (dotnet.exe) — TaskHostTask.Execute():
  Event 109: TaskHostDispatchStart
    ├─ Serialize task configuration               — TaskHostTask builds TaskHostConfiguration packet
    ├─ Acquire/launch task host process            — NodeProviderOutOfProcTaskHost.AcquireAndSetUpHost()
    ├─ Send config via IPC pipe                    — NodeProviderOutOfProcTaskHost sends packet
    │
    │   Task host process (MSBuild.exe) — OutOfProcTaskHostNode.RunTask():
    │     ├─ Set environment, culture              — OutOfProcTaskHostNode sets up env
    │     ├─ Load task assembly                    — OutOfProcTaskAppDomainWrapperBase.ExecuteTask()
    │     ├─ Create task instance + set params     — TaskLoader.CreateTask()
    │     │
    │     Event 111: TaskExecuteInHostStart         (in OutOfProcTaskAppDomainWrapperBase)
    │     │  └─ wrappedTask.Execute()              ← actual work (e.g. Copy.Execute())
    │     Event 112: TaskExecuteInHostStop
    │     │
    │     ├─ Collect output parameters             — OutOfProcTaskAppDomainWrapperBase collects outputs
    │     └─ Send TaskHostTaskComplete via IPC     — OutOfProcTaskHostNode.CompleteTask()
    │
    ├─ Receive TaskHostTaskComplete packet         — TaskHostTask.HandleTaskHostTaskComplete()
  Event 110: TaskHostDispatchStop

How to compute overhead

Both Stop events include DURATION_MSEC (auto-calculated by ETW). For each task type.
Dispatch events (main process) and ExecuteInHost events (task host process) are in different processes on different threads — there is no shared ActivityID linking a specific dispatch to its corresponding execute. Instead, we aggregate durations per task type:

All Dispatch Stop events for "Copy" → sum durations → total dispatch time
All Execute Stop events for "Copy" → sum durations → total execute time
Copy overhead = total dispatch − total execute
Overhead % = overhead / total dispatch × 100

The script validates that dispatch and execute event counts match per task type. If counts differ, a warning is printed.

CSV column definitions (task_host_summary.csv)

Column	How it's calculated
task_name	Fully qualified task class name, extracted from taskName field in ETW event
dispatch_count	Number of TaskHostDispatch/Stop events for this task type
execute_count	Number of TaskExecuteInHost/Stop events for this task type. Should equal dispatch_count; If not equal it mean that event had a missing duration time.
total_dispatch_ms	Sum of DURATION_MSEC from all TaskHostDispatch/Stop events — total wall-clock time in the main process (includes IPC + remote execution + result retrieval)
total_execute_ms	Sum of DURATION_MSEC from all TaskExecuteInHost/Stop events — total time inside the task host running task.Execute()
total_overhead_ms	total_dispatch_ms − total_execute_ms — time spent on IPC, serialization, environment setup, assembly loading, and parameter marshaling
avg_dispatch_ms	total_dispatch_ms / dispatch_count — average dispatch roundtrip per invocation
avg_execute_ms	total_execute_ms / execute_count — average actual task execution per invocation (uses its own count to avoid cross-dividing when counts differ)
avg_overhead_ms	total_overhead_ms / dispatch_count — average overhead per invocation
overhead_pct	total_overhead_ms / total_dispatch_ms × 100 — percentage of dispatch time that is overhead

How to Collect Measurements

1. Delete all [MSBuildMultiThreadableTask] from tasks

2. Build MSBuild with these changes

.\build.cmd 

3. Clean up previous build

D:\msbuild\artifacts\bin\bootstrap\core\dotnet.exe build-server shutdown
D:\msbuild\artifacts\bin\bootstrap\core\dotnet.exe clean

4. Collect ETW trace with PerfView

PerfView.exe  "/DataFile:PerfViewData.etl" /BufferSizeMB:256 /StackCompression /CircularMB:2048 /KernelEvents:None /Process:"dotnet" /ClrEvents:None /Providers:"*Microsoft-Build" /NoGui /NoNGenRundown /Merge:False /Zip:False run D:\msbuild\artifacts\bin\bootstrap\core\dotnet.exe build D:\OrchardCore\OrchardCore.slnx --no-restore -mt

5. Export events from PerfView

Open the .etl in PerfView → Events tab → filter Microsoft-Build → select event types (TaskHostDispatchStart/Stop, TaskExecuteInHostStart/stop) → Make sure that MaxRet parameter is set to all events → Load view → Save View As CSV.

6. Run analysis scripts

parse_overhead.py

python parse_overhead.py        # produces task_host_summary.csv

[OvesN]

Measured https://github.com/OrchardCMS/OrchardCore build task overhead.

Command used:

D:\msbuild\artifacts\bin\bootstrap\core\dotnet.exe build-server shutdown
D:\msbuild\artifacts\bin\bootstrap\core\dotnet.exe clean
PerfView.exe  "/DataFile:PerfViewData.etl" /BufferSizeMB:256 /StackCompression /CircularMB:2048 /KernelEvents:None /Process:"dotnet" /ClrEvents:None /Providers:"*Microsoft-Build" /NoGui /NoNGenRundown /Merge:False /Zip:False run D:\msbuild\artifacts\bin\bootstrap\core\dotnet.exe build D:\OrchardCore\OrchardCore.slnx --no-restore -mt

task_host_summary.csv

[Copilot]

Pull request overview

Adds new ETW instrumentation to quantify out-of-proc task host overhead in MT builds by measuring (1) main-process task-host dispatch roundtrips and (2) in-task-host task.Execute() durations.

Changes:

• Added four new ETW events (IDs 107–110) to MSBuildEventSource to mark task-host dispatch and in-host execution start/stop.
• Instrumented TaskHostTask.Execute() (main process) with dispatch start/stop events.
• Instrumented OutOfProcTaskAppDomainWrapperBase (task host process) with in-host execution start/stop events.

Reviewed changes

Copilot reviewed 3 out of 3 changed files in this pull request and generated 2 comments.

File	Description
src/MSBuild/OutOfProcTaskAppDomainWrapperBase.cs	Emits ETW start/stop around wrappedTask.Execute() inside the task host process.
src/Framework/MSBuildEventSource.cs	Defines new ETW events for task-host dispatch and in-host execution timing.
src/Build/Instance/TaskFactories/TaskHostTask.cs	Emits ETW start/stop around the main-process task-host roundtrip.

[AR-May]

LGTM