Emit explicit telemetry when workload execution is canceled due to experiment timeout (#697)

* Emit explicit telemetry when workload is canceled due to experiment timeout

Add warning-level telemetry events in two key locations:
1. ProfileExecutor.ExperimentTimeoutReached - logged when the experiment
   timeout is reached, before canceling in-progress workloads
2. {TypeName}.ExecutionCancelled - logged per-component when an
   OperationCanceledException is caught due to cancellation token

Both events include a structured 'terminationReason' field set to
'ExperimentTimeout' and a descriptive message to help users and
dashboards distinguish timeout-induced cancellations from real failures.

Agent-Logs-Url: https://github.com/microsoft/VirtualClient/sessions/ed26e102-6dfe-4c37-ab5f-c52008932555

---------

Co-authored-by: copilot-swe-agent[bot] <198982749+Copilot@users.noreply.github.com>
Co-authored-by: nchapagain001 <165215502+nchapagain001@users.noreply.github.com>
Co-authored-by: Nirjan Chapagain <nchapagain@example.com>

Author: 3 people

src/VirtualClient/VirtualClient.Contracts.UnitTests/VirtualClientComponentTests.cs

@@ -668,6 +668,53 @@ public async Task VirtualClientComponentLogsExpectedMetricsOnFailedExecutions_Sc
                 && context.Properties["toolName"].ToString() == component.TypeName);
         }
 
+        [Test]
+        public async Task VirtualClientComponentLogsExplicitTelemetryWhenExecutionIsCancelled()
+        {
+            // Scenario:
+            // The cancellation token is cancelled while the component is executing.
+            // The component should emit explicit telemetry indicating the execution was cancelled.
+            using (CancellationTokenSource cts = new CancellationTokenSource())
+            {
+                TestVirtualClientComponent component = new TestVirtualClientComponent(this.mockFixture.Dependencies, this.mockFixture.Parameters);
+                component.OnExecute = (EventContext telemetryContext, CancellationToken cancellationToken) =>
+                {
+                    cts.Cancel();
+                    cancellationToken.ThrowIfCancellationRequested();
+                };
+
+                await component.ExecuteAsync(cts.Token);
+
+                var cancelMessages = this.mockFixture.Logger.MessagesLogged($"{component.TypeName}.ExecutionCancelled");
+                Assert.IsNotEmpty(cancelMessages);
+                Assert.AreEqual(1, cancelMessages.Count());
+
+                EventContext context = cancelMessages.First().Item3 as EventContext;
+                Assert.IsNotNull(context);
+                Assert.IsTrue(context.Properties.ContainsKey("executionCancelled"));
+                Assert.AreEqual(true, context.Properties["executionCancelled"]);
+            }
+        }
+
+        [Test]
+        public async Task VirtualClientComponentDoesNotLogCancellationTelemetryWhenTokenIsNotCancelled()
+        {
+            // Scenario:
+            // The component throws OperationCanceledException for reasons other than
+            // cancellation token being cancelled (e.g. Task.Delay cancellation).
+            // No cancellation telemetry should be emitted.
+            TestVirtualClientComponent component = new TestVirtualClientComponent(this.mockFixture.Dependencies, this.mockFixture.Parameters);
+            component.OnExecute = (EventContext telemetryContext, CancellationToken cancellationToken) =>
+            {
+                throw new OperationCanceledException();
+            };
+
+            await component.ExecuteAsync(CancellationToken.None);
+
+            var cancelMessages = this.mockFixture.Logger.MessagesLogged($"{component.TypeName}.ExecutionCancelled");
+            Assert.IsEmpty(cancelMessages);
+        }
+
         [Test]
         public void VirtualClientComponentIsSupportedRespectsSupportedPlatformAttribute()
         {

src/VirtualClient/VirtualClient.Contracts/VirtualClientComponent.cs

@@ -780,6 +780,13 @@ await this.Logger.LogMessageAsync($"{this.TypeName}.Execute", telemetryContext,
                         catch (OperationCanceledException)
                         {
                             // Expected for cases where a cancellation token is cancelled.
+                            if (cancellationToken.IsCancellationRequested)
+                            {
+                                EventContext cancelContext = telemetryContext.Clone()
+                                    .AddContext("executionCancelled", true);
+
+                                this.Logger.LogMessage($"{this.TypeName}.ExecutionCancelled", LogLevel.Warning, cancelContext);
+                            }
                         }
                         catch (Exception)
                         {

src/VirtualClient/VirtualClient.Core.UnitTests/ProfileExecutorTests.cs

@@ -861,6 +861,40 @@ public async Task ProfileExecutorExitsImmediatelyOnAnyErrorWheneverTheFailFastOp
             }
         }
 
+        [Test]
+        public async Task ProfileExecutorLogsExplicitTelemetryWhenExperimentTimeoutIsReached()
+        {
+            // Scenario:
+            // An explicit timeout is provided and the profile executor reaches that timeout.
+            // The executor should emit explicit telemetry indicating the experiment timeout was reached.
+            using (TestProfileExecutor executor = new TestProfileExecutor(this.mockProfile, this.mockFixture.Dependencies, logger: this.mockFixture.Logger))
+            {
+                executor.ExecuteActions = true;
+                executor.ExecuteDependencies = false;
+
+                ProfileTiming explicitTimeout = new ProfileTiming(TimeSpan.FromMicroseconds(50));
+                Task executionTask = executor.ExecuteAsync(explicitTimeout, CancellationToken.None);
+
+                while (!executionTask.IsCompleted)
+                {
+                    await Task.Delay(10).ConfigureAwait(false);
+                }
+
+                executionTask.ThrowIfErrored();
+
+                Assert.IsTrue(explicitTimeout.IsTimedOut);
+
+                var timeoutMessages = this.mockFixture.Logger.MessagesLogged("ProfileExecutor.ExperimentTimeoutReached");
+                Assert.IsNotEmpty(timeoutMessages);
+                Assert.AreEqual(1, timeoutMessages.Count());
+
+                EventContext context = timeoutMessages.First().Item3 as EventContext;
+                Assert.IsNotNull(context);
+                Assert.IsTrue(context.Properties.ContainsKey("timeout"));
+                Assert.IsTrue(context.Properties.ContainsKey("timeoutTimestamp"));
+            }
+        }
+
         private class TestProfileExecutor : ProfileExecutor
         {
             public TestProfileExecutor(ExecutionProfile profile, IServiceCollection dependencies, ComponentSettings settings = null, IEnumerable<string> scenarios = null, ILogger logger = null)

src/VirtualClient/VirtualClient.Core/ProfileExecutor.cs

@@ -268,6 +268,16 @@ public async Task ExecuteAsync(ProfileTiming timing, CancellationToken cancellat
                         }
 
                         // If we timeout or a reboot is requested, we will request all background processes to cancel/exit.
+                        if (timing.IsTimedOut)
+                        {
+                            EventContext timeoutContext = EventContext.Persisted()
+                                .AddContext("timeout", timing.Duration)
+                                .AddContext("timeoutTimestamp", timing.Timeout);
+
+                            this.Logger.LogMessage($"{nameof(ProfileExecutor)}.ExperimentTimeoutReached", LogLevel.Warning, timeoutContext);
+                            ConsoleLogger.Default.LogWarning("Profile: Experiment timeout reached. Canceling in-progress workloads.");
+                        }
+
                         await tokenSource.CancelAsync();
 
                         // We allow the user to supply an instruction on the command line to force the application