Move request cancellations to a separate log

Author: MihaZupan

src/ReverseProxy/Forwarder/HttpForwarder.cs

@@ -982,6 +982,11 @@ private static class Log
             EventIds.ForwardingError,
             "{error}: {message}");
 
+        private static readonly Action<ILogger, ForwarderError, string, Exception> _proxyRequestCancelled = LoggerMessage.Define<ForwarderError, string>(
+            LogLevel.Debug,
+            EventIds.ForwardingRequestCancelled,
+            "{error}: {message}");
+
         private static readonly Action<ILogger, int, Exception?> _notProxying = LoggerMessage.Define<int>(
             LogLevel.Information,
             EventIds.NotForwarding,
@@ -1031,7 +1036,21 @@ public static void InvalidSecWebSocketKeyHeader(ILogger logger, string? key)
 
         public static void ErrorProxying(ILogger logger, ForwarderError error, Exception ex)
         {
-            _proxyError(logger, error, GetMessage(error), ex);
+            var message = GetMessage(error);
+
+            if (error is
+                ForwarderError.RequestCanceled or
+                ForwarderError.RequestBodyCanceled or
+                ForwarderError.UpgradeRequestCanceled)
+            {
+                // These error conditions are triggered by the client and are not generally indicative of a problem with the proxy.
+                // It's unlikely that they will be useful in most cases, so we log them at Debug level to reduce noise.
+                _proxyRequestCancelled(logger, error, message, ex);
+            }
+            else
+            {
+                _proxyError(logger, error, message, ex);
+            }
         }
 
         public static void RetryingWebSocketDowngradeNoConnect(ILogger logger)

src/ReverseProxy/Utilities/EventIds.cs

@@ -69,4 +69,5 @@ internal static class EventIds
     public static readonly EventId InvalidSecWebSocketKeyHeader = new EventId(63, "InvalidSecWebSocketKeyHeader");
     public static readonly EventId TimeoutNotApplied = new(64, nameof(TimeoutNotApplied));
     public static readonly EventId DelegationQueueNoLongerExists = new(65, nameof(DelegationQueueNoLongerExists));
+    public static readonly EventId ForwardingRequestCancelled = new(66, nameof(ForwardingRequestCancelled));
 }

test/ReverseProxy.Tests/Common/TestEventListener.cs

@@ -1,7 +1,6 @@
 // Licensed to the .NET Foundation under one or more agreements.
 // The .NET Foundation licenses this file to you under the MIT license.
 
-using System;
 using System.Collections.Generic;
 using System.Diagnostics.Tracing;
 using System.Threading;
@@ -10,13 +9,12 @@ namespace Yarp.Tests.Common;
 
 internal static class TestEventListener
 {
-    private static readonly AsyncLocal<List<EventWrittenEventArgs>> _eventsAsyncLocal = new AsyncLocal<List<EventWrittenEventArgs>>();
-    private static readonly InternalEventListener _listener = new InternalEventListener();
+    private static readonly AsyncLocal<List<EventWrittenEventArgs>> _eventsAsyncLocal = new();
+#pragma warning disable IDE0052 // Remove unread private members
+    private static readonly InternalEventListener _listener = new();
+#pragma warning restore IDE0052
 
-    public static List<EventWrittenEventArgs> Collect()
-    {
-        return _eventsAsyncLocal.Value = new List<EventWrittenEventArgs>();
-    }
+    public static List<EventWrittenEventArgs> Collect() => _eventsAsyncLocal.Value ??= [];
 
     private sealed class InternalEventListener : EventListener
     {
@@ -28,14 +26,7 @@ protected override void OnEventSourceCreated(EventSource eventSource)
             }
         }
 
-        protected override void OnEventWritten(EventWrittenEventArgs eventData)
-        {
-            if (eventData.EventId == 0)
-            {
-                throw new Exception($"EventSource error received: {eventData.Payload[0]}");
-            }
-
+        protected override void OnEventWritten(EventWrittenEventArgs eventData) =>
             _eventsAsyncLocal.Value?.Add(eventData);
-        }
     }
 }

test/ReverseProxy.Tests/Common/TestLogger.cs

@@ -0,0 +1,29 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+using System;
+using System.Collections.Generic;
+using System.Threading;
+using Microsoft.Extensions.Logging;
+
+namespace Yarp.ReverseProxy.Common;
+
+internal sealed class TestLogger(ILogger xunitLogger, string categoryName) : ILogger
+{
+    public record LogEntry(string CategoryName, LogLevel LogLevel, EventId EventId, string Message, Exception Exception);
+
+    private static readonly AsyncLocal<List<LogEntry>> _logsAsyncLocal = new();
+
+    public static List<LogEntry> Collect() => _logsAsyncLocal.Value ??= [];
+
+    public IDisposable BeginScope<TState>(TState state) where TState : notnull => xunitLogger.BeginScope(state);
+
+    public bool IsEnabled(LogLevel logLevel) => true;
+
+    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
+    {
+        _logsAsyncLocal.Value?.Add(new LogEntry(categoryName, logLevel, eventId, formatter(state, exception), exception));
+
+        xunitLogger.Log(logLevel, eventId, state, exception, formatter);
+    }
+}

test/ReverseProxy.Tests/Common/TestLoggerProvider.cs

@@ -0,0 +1,17 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Testing;
+using Xunit.Abstractions;
+
+namespace Yarp.ReverseProxy.Common;
+
+internal sealed class TestLoggerProvider(ITestOutputHelper output) : ILoggerProvider
+{
+    private readonly XunitLoggerProvider _xunitLoggerProvider = new(output);
+
+    public ILogger CreateLogger(string categoryName) => new TestLogger(_xunitLoggerProvider.CreateLogger(categoryName), categoryName);
+
+    public void Dispose() => _xunitLoggerProvider.Dispose();
+}