fix(core): surface activity processing timeouts

docs/design-decouple-cancellation-token.md

@@ -57,19 +57,31 @@ await MiddleWare.RunPipelineAsync(this, activity, this.OnActivity, 0, token);
 
 The HTTP request's `cancellationToken` is no longer forwarded to the handler pipeline.
 
-#### 3. Graceful timeout handling
+#### 3. Timeout handling
 
-A new catch clause handles the timeout without crashing:
+A dedicated catch clause records the timeout and then surfaces it as a turn failure:
 
 ```csharp
 catch (OperationCanceledException) when (cts.IsCancellationRequested)
 {
-    _logger.LogWarning("Activity processing timed out after {Timeout}: Id={Id}",
-        _processActivityTimeout, activity.Id);
+    _logger.ActivityTimedOut(_processActivityTimeout, activity.Id); // LogLevel.Error
+    Telemetry.HandlerErrors.Add(1, activityTypeTag);
+    TimeoutException timeoutException = new($"Activity processing exceeded the configured ProcessActivityTimeout of {_processActivityTimeout}.");
+    span.RecordException(timeoutException);
+    span?.SetStatus(ActivityStatusCode.Error, "timeout");
+    throw new BotHandlerException("Activity processing timed out", timeoutException, activity);
 }
 ```
 
-This prevents `BotHandlerException` from being thrown when the timeout fires, which is a recoverable situation (the handler simply took too long).
+Each transport then reports the turn as failed, the same way it handles any other `BotHandlerException`:
+
+- **HTTP**: the exception propagates to the endpoint, producing a 500 if the response has not started.
+- **Socket Mode**: `SocketModeTransport` replies with a 500 (or a 500 ack for non-invoke activities) and invokes the error hook.
+- **BotBuilder compat**: `TeamsBotFrameworkHttpAdapter` invokes `OnTurnError`.
+
+The timeout is cooperative. It only takes effect when the handler (or the I/O it performs) observes the cancellation token. A handler that ignores the token or does blocking I/O keeps running past the timeout and is not surfaced this way. The timeout is also disabled when a debugger is attached.
+
+> **History:** this catch originally logged a warning and returned normally, treating a timeout as recoverable. That caused timed-out turns to be acknowledged as successful (HTTP 200, Socket Mode 200), hiding the failure from the sender, so timeouts are now surfaced as `BotHandlerException`.
 
 ## Design Decisions
 
@@ -92,7 +104,7 @@ Unbounded processing is a resource leak risk. A timeout provides a safety net:
 
 ### Impact on non-streaming bots
 
-Non-streaming handlers that complete within the HTTP request lifetime are unaffected. The 5-minute default is well above typical synchronous handler durations. Apps that want tighter timeouts can set `ProcessActivityTimeout` to a lower value.
+Non-streaming handlers that complete within the HTTP request lifetime are unaffected. The 5-minute default is well above typical synchronous handler durations. Apps that want tighter timeouts can set `ProcessActivityTimeout` to a lower value. A turn that exceeds the timeout (including a long-running streaming turn) fails with a `BotHandlerException` and the transport reports an error; apps that legitimately need longer turns can raise `ProcessActivityTimeout` or set it to `Timeout.InfiniteTimeSpan`.
 
 ## Alternatives Considered
 

src/Microsoft.Teams.Core/BotApplication.cs

@@ -185,7 +185,13 @@ public BotApplication(ConversationClient conversationClient, UserTokenClient use
     /// <returns>A task that represents the asynchronous activity processing operation.</returns>
     /// <exception cref="InvalidOperationException">Thrown if the request body cannot be deserialized into a valid activity.</exception>
     /// <exception cref="InvalidDataException">Thrown if the activity's service URL does not match the <c>serviceurl</c> claim of the authenticated caller.</exception>
-    /// <exception cref="BotHandlerException">Thrown if an error occurs while processing the activity, wrapping the original exception and the offending <see cref="CoreActivity"/>.</exception>
+    /// <exception cref="BotHandlerException">Thrown if an error occurs while processing the activity, wrapping the original exception and the offending <see cref="CoreActivity"/>.
+    /// Also thrown when processing exceeds <see cref="BotApplicationOptions.ProcessActivityTimeout"/> and the pipeline observes
+    /// the resulting cancellation, in which case <see cref="Exception.InnerException"/> is a <see cref="TimeoutException"/>.
+    /// A <see cref="TimeoutException"/> thrown by a handler is wrapped the same way, so an inner <see cref="TimeoutException"/>
+    /// does not by itself indicate that <see cref="BotApplicationOptions.ProcessActivityTimeout"/> elapsed.
+    /// The timeout is cooperative: a handler that ignores its cancellation token or performs blocking I/O keeps running past
+    /// the timeout and is not surfaced this way. The timeout is disabled when a debugger is attached.</exception>
     public virtual async Task ProcessAsync(HttpContext httpContext, CancellationToken cancellationToken = default)
     {
         ArgumentNullException.ThrowIfNull(httpContext);
@@ -225,7 +231,13 @@ await ProcessAsync(
     /// <param name="cancellationToken">Reserved for the caller's cancellation. Note: a dedicated timeout governs activity processing.</param>
     /// <returns>A task that represents the asynchronous activity processing operation.</returns>
     /// <exception cref="InvalidDataException">Thrown if the activity's service URL does not match the <c>serviceurl</c> claim of <paramref name="user"/>.</exception>
-    /// <exception cref="BotHandlerException">Thrown if an error occurs while processing the activity, wrapping the original exception and the offending <see cref="CoreActivity"/>.</exception>
+    /// <exception cref="BotHandlerException">Thrown if an error occurs while processing the activity, wrapping the original exception and the offending <see cref="CoreActivity"/>.
+    /// Also thrown when processing exceeds <see cref="BotApplicationOptions.ProcessActivityTimeout"/> and the pipeline observes
+    /// the resulting cancellation, in which case <see cref="Exception.InnerException"/> is a <see cref="TimeoutException"/>.
+    /// A <see cref="TimeoutException"/> thrown by a handler is wrapped the same way, so an inner <see cref="TimeoutException"/>
+    /// does not by itself indicate that <see cref="BotApplicationOptions.ProcessActivityTimeout"/> elapsed.
+    /// The timeout is cooperative: a handler that ignores its cancellation token or performs blocking I/O keeps running past
+    /// the timeout and is not surfaced this way. The timeout is disabled when a debugger is attached.</exception>
     public virtual async Task ProcessAsync(CoreActivity activity, ClaimsPrincipal? user, string? correlationVector, CancellationToken cancellationToken = default)
     {
         ArgumentNullException.ThrowIfNull(activity);
@@ -277,7 +289,11 @@ public virtual async Task ProcessAsync(CoreActivity activity, ClaimsPrincipal? u
             {
                 _logger.ActivityTimedOut(_processActivityTimeout, activity.Id);
                 Telemetry.HandlerErrors.Add(1, activityTypeTag);
+                TimeoutException timeoutException = new($"Activity processing exceeded the configured ProcessActivityTimeout of {_processActivityTimeout}.");
+                // RecordException sets the status from the exception message; set "timeout" afterward so it wins.
+                span.RecordException(timeoutException);
                 span?.SetStatus(ActivityStatusCode.Error, "timeout");
+                throw new BotHandlerException("Activity processing timed out", timeoutException, activity);
             }
             catch (Exception ex)
             {

src/Microsoft.Teams.Core/Hosting/BotApplicationOptions.cs

@@ -18,6 +18,11 @@ public class BotApplicationOptions
     /// This timeout replaces the HTTP request's cancellation token so that handlers
     /// (especially streaming handlers) are not canceled when the incoming HTTP connection closes.
     /// Defaults to 5 minutes. Set to <see cref="Timeout.InfiniteTimeSpan"/> to disable the timeout.
+    /// The timeout is cooperative: it cancels the token passed to middleware and handlers. When the pipeline
+    /// observes that cancellation, processing fails with a <see cref="BotHandlerException"/> whose
+    /// <see cref="Exception.InnerException"/> is a <see cref="TimeoutException"/>, so the inbound transport
+    /// reports the turn as failed. Handlers that ignore the token or perform blocking I/O are not interrupted.
+    /// The timeout is disabled when a debugger is attached.
     /// </summary>
     public TimeSpan ProcessActivityTimeout { get; set; } = TimeSpan.FromMinutes(5);
 }

src/Microsoft.Teams.Core/Log.cs

@@ -31,7 +31,7 @@ internal static partial class Log
     [LoggerMessage(EventId = 4, Level = LogLevel.Trace, Message = "Received activity: \n {Activity}")]
     public static partial void ReceivedActivityJson(this ILogger logger, string activity);
 
-    [LoggerMessage(EventId = 5, Level = LogLevel.Warning, Message = "Activity processing timed out after {Timeout}: Id={Id}")]
+    [LoggerMessage(EventId = 5, Level = LogLevel.Error, Message = "Activity processing timed out after {Timeout}: Id={Id}")]
     public static partial void ActivityTimedOut(this ILogger logger, TimeSpan timeout, string? id);
 
     [LoggerMessage(EventId = 6, Level = LogLevel.Error, Message = "Error processing activity: Id={Id}")]

test/Microsoft.Teams.Apps.BotBuilder.UnitTests/CompatAdapterTests.cs

@@ -8,6 +8,7 @@
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.Logging.Abstractions;
 using Microsoft.Teams.Core;
+using Microsoft.Teams.Core.Hosting;
 using Microsoft.Teams.Core.Http;
 using Microsoft.Teams.Core.Schema;
 using Moq;
@@ -168,15 +169,56 @@ public async Task ProcessAsync_OnTurnError_ReceivesTurnContextWithTurnState()
             Assert.Equal("customTurnStateValue", capturedCustomTurnState);
         }
 
-        private static TeamsBotFrameworkHttpAdapter CreateCompatAdapter(UserTokenClient? userTokenClient = null)
+        [Fact]
+        public async Task ProcessAsync_Timeout_InvokesOnTurnErrorWithTimeout()
+        {
+            // Arrange
+            TeamsBotFrameworkHttpAdapter adapter = CreateCompatAdapter(processActivityTimeout: TimeSpan.FromMilliseconds(50));
+
+            Exception? capturedException = null;
+            adapter.OnTurnError = (_, exception) =>
+            {
+                capturedException = exception;
+                return Task.CompletedTask;
+            };
+
+            Mock<IBot> mockBot = new();
+            // Bounded rather than infinite: with a debugger attached the processing timeout is disabled, so this fails instead of hanging.
+            mockBot
+                .Setup(b => b.OnTurnAsync(It.IsAny<ITurnContext>(), It.IsAny<CancellationToken>()))
+                .Returns<ITurnContext, CancellationToken>((_, ct) => Task.Delay(TimeSpan.FromSeconds(10), ct));
+
+            CoreActivity activity = new()
+            {
+                Type = ActivityType.Message,
+                Id = "act123",
+                ServiceUrl = new Uri("https://smba.trafficmanager.net/teams/"),
+                Conversation = new Conversation("conv123"),
+                From = new Teams.Core.Schema.ChannelAccount { Id = "user123" }
+            };
+
+            DefaultHttpContext httpContext = new();
+            httpContext.Request.Body = new MemoryStream(Encoding.UTF8.GetBytes(activity.ToJson()));
+            httpContext.Request.ContentType = "application/json";
+
+            // Act
+            await adapter.ProcessAsync(httpContext.Request, httpContext.Response, mockBot.Object, CancellationToken.None);
+
+            // Assert
+            BotHandlerException botHandlerException = Assert.IsType<BotHandlerException>(capturedException);
+            Assert.IsType<TimeoutException>(botHandlerException.InnerException);
+        }
+
+        private static TeamsBotFrameworkHttpAdapter CreateCompatAdapter(UserTokenClient? userTokenClient = null, TimeSpan? processActivityTimeout = null)
         {
             HttpClient httpClient = new();
             ConversationClient conversationClient = new(httpClient, NullLogger<ConversationClient>.Instance);
 
             BotApplication botApplication = new(
                 conversationClient,
                 userTokenClient ?? CreateMockUserTokenClient().Object,
-                NullLogger<BotApplication>.Instance);
+                NullLogger<BotApplication>.Instance,
+                processActivityTimeout is null ? null : new BotApplicationOptions { ProcessActivityTimeout = processActivityTimeout.Value });
 
             TeamsBotFrameworkHttpAdapter compatAdapter = new(
                 botApplication,

test/Microsoft.Teams.Apps.UnitTests/SocketMode/SocketModeHostingTests.cs

@@ -216,6 +216,24 @@ public async Task DispatchAsync_NonInvokeReturnsOkWithoutBody()
         Assert.Equal(new SocketDispatchResult(200), result);
     }
 
+    [Fact]
+    public async Task DispatchAsync_ProcessingTimeout_ThrowsBotHandlerException()
+    {
+        ServiceCollection services = CreateServices();
+        services.AddTeamsBotApplication(options => options.ProcessActivityTimeout = TimeSpan.FromMilliseconds(50));
+        await using ServiceProvider provider = services.BuildServiceProvider();
+        TeamsBotApplication app = provider.GetRequiredService<TeamsBotApplication>();
+        // Bounded rather than infinite: with a debugger attached the processing timeout is disabled, so this fails instead of hanging.
+        app.OnMessage((_, ct) => Task.Delay(TimeSpan.FromSeconds(10), ct));
+
+        Core.BotHandlerException exception = await Assert.ThrowsAsync<Core.BotHandlerException>(() =>
+            SocketModeServiceRegistration.DispatchAsync(
+                app,
+                new Core.Schema.CoreActivity { Type = TeamsActivityTypes.Message }));
+
+        Assert.IsType<TimeoutException>(exception.InnerException);
+    }
+
     [Fact]
     public async Task UseTeamsBotApplication_WithSocketMode_ThrowsAndMapsNothing()
     {

test/Microsoft.Teams.Core.UnitTests/BotApplicationTests.cs

@@ -411,11 +411,59 @@ public override Task ProcessAsync(CoreActivity activity, ClaimsPrincipal? user,
         }
     }
 
+    [Fact]
+    public async Task ProcessAsync_CoreActivity_Timeout_ThrowsBotHandlerExceptionWithTimeoutInner()
+    {
+        BotApplication botApp = CreateBotApplication(TimeSpan.FromMilliseconds(50));
+        // Bounded rather than infinite: with a debugger attached the processing timeout is disabled, so this fails instead of hanging.
+        botApp.OnActivity = (_, ct) => Task.Delay(TimeSpan.FromSeconds(10), ct);
+        CoreActivity activity = new(ActivityType.Message) { Id = "act123" };
+
+        BotHandlerException exception = await Assert.ThrowsAsync<BotHandlerException>(() =>
+            botApp.ProcessAsync(activity, user: null, correlationVector: null));
+
+        Assert.IsType<TimeoutException>(exception.InnerException);
+        Assert.Same(activity, exception.Activity);
+    }
+
+    [Fact]
+    public async Task ProcessAsync_HttpContext_Timeout_ThrowsBotHandlerException()
+    {
+        BotApplication botApp = CreateBotApplication(TimeSpan.FromMilliseconds(50));
+        // Bounded rather than infinite: with a debugger attached the processing timeout is disabled, so this fails instead of hanging.
+        botApp.OnActivity = (_, ct) => Task.Delay(TimeSpan.FromSeconds(10), ct);
+        CoreActivity activity = new(ActivityType.Message) { Id = "act123" };
+        DefaultHttpContext httpContext = CreateHttpContextWithActivity(activity);
+
+        BotHandlerException exception = await Assert.ThrowsAsync<BotHandlerException>(() =>
+            botApp.ProcessAsync(httpContext));
+
+        Assert.IsType<TimeoutException>(exception.InnerException);
+        Assert.Equal("act123", exception.Activity?.Id);
+    }
+
+    [Fact]
+    public async Task ProcessAsync_HandlerThrowsTimeoutException_ThrowsBotHandlerException()
+    {
+        BotApplication botApp = CreateBotApplication();
+        TimeoutException handlerException = new("handler timeout");
+        botApp.OnActivity = (_, _) => throw handlerException;
+        CoreActivity activity = new(ActivityType.Message) { Id = "act123" };
+
+        BotHandlerException exception = await Assert.ThrowsAsync<BotHandlerException>(() =>
+            botApp.ProcessAsync(activity, user: null, correlationVector: null));
+
+        Assert.Same(handlerException, exception.InnerException);
+        Assert.Equal("Error processing activity", exception.Message);
+        Assert.Same(activity, exception.Activity);
+    }
+
     private static BotApplicationOptions CreateOptions(string appId) =>
         new() { AppId = appId };
 
-    private static BotApplication CreateBotApplication() =>
-        new(CreateMockConversationClient(), CreateMockUserTokenClient(), NullLogger<BotApplication>.Instance);
+    private static BotApplication CreateBotApplication(TimeSpan? processActivityTimeout = null) =>
+        new(CreateMockConversationClient(), CreateMockUserTokenClient(), NullLogger<BotApplication>.Instance,
+            processActivityTimeout is null ? null : new BotApplicationOptions { ProcessActivityTimeout = processActivityTimeout.Value });
 
     private static ConversationClient CreateMockConversationClient()
     {