Filter AWS SDK trace noise by default

.github/workflows/api-compatibility.yml

@@ -32,7 +32,7 @@ jobs:
     - name: Setup .NET
       uses: actions/setup-dotnet@v4
       with:
-        dotnet-version: '8.0.x'
+        dotnet-version: '10.0.x'
 
     - name: Install Microsoft.DotNet.ApiCompat.Tool
       run: dotnet tool install --global Microsoft.DotNet.ApiCompat.Tool

.github/workflows/ci.yml

@@ -19,7 +19,7 @@ jobs:
       - name: Setup .NET
         uses: actions/setup-dotnet@v4
         with:
-          dotnet-version: 8.0.x
+          dotnet-version: 10.0.x
 
       - name: Build
         run: dotnet build

.github/workflows/publish.yml

@@ -20,7 +20,7 @@ jobs:
       - name: Setup .NET
         uses: actions/setup-dotnet@v4
         with:
-          dotnet-version: 8.0.x
+          dotnet-version: 10.0.x
 
       - name: Build
         run: dotnet build

docs/setup.md

@@ -38,6 +38,63 @@ static void Main() {
 }
 ```
 
+### AWS Provider
+
+```bash
+PM> Install-Package Spiffy.Monitoring.Aws
+```
+
+Routes the AWS SDK's own diagnostics into your structured logs as `Component=AwsSdk Operation=Event`.
+
+```csharp
+static void Main() {
+    Spiffy.Monitoring.Configuration.Initialize(spiffy => {
+        spiffy.Providers.Aws();
+    });
+}
+```
+
+Each event's level comes from the severity the SDK reported it at.
+
+Where the SDK hands the exception to the trace listener, it is broken out into `Exception_*` fields.
+Only v3 of the AWS SDK does so: v4 discards the exception before the listener sees it, keeping only
+the message text. So don't build alerting on `Exception_*` for a v4 application.
+
+The SDK reports a lot at informational severity, including several messages that repeat on every call
+and carry nothing actionable: its own user-agent string, request-signing canonicalization, retry
+bookkeeping, buffer resizing, DynamoDB table descriptions, and one line per unset `AWS_*` environment
+variable. Those are filtered by default; anything the SDK reports at warning or above never is.
+
+Retry and failure notices are kept, including the ones the SDK reports at informational severity, so
+a throttled DynamoDB request or a rejected S3 request still reaches your logs.
+
+There's one filter per kind, and each kind is a member of `SdkNoise`, so you don't have to know the
+message text. Remove a filter and that kind shows up in your logs again:
+
+```csharp
+spiffy.Providers.Aws(c => c.NoiseFilters.Remove(SdkNoise.UserAgentHeader));
+```
+
+To filter noise `SdkNoise` doesn't name (something specific to your application, or a message a
+newer SDK started reporting), add a filter matching the start of the message:
+
+```csharp
+spiffy.Providers.Aws(c => c.NoiseFilters.Add("Credentials found using"));
+```
+
+`Clear` removes every filter, so everything the SDK reports is logged. Useful when you're working out
+what to filter:
+
+```csharp
+spiffy.Providers.Aws(c => c.NoiseFilters.Clear());
+```
+
+Response bodies are logged on error only. `Always` logs them for every call, `Never` for none:
+
+```csharp
+spiffy.Providers.Aws(c => c.LogResponses.Always());
+```
+
 ## Multiple Providers
 
 Multiple providers can be supplied, for example, this application uses both `Console` (built-in), as well as `File` (NLog)

src/Spiffy.Monitoring.Aws/AwsConfigurationApi.cs

@@ -1,4 +1,6 @@
 using System;
+using System.Collections.Generic;
+using System.Linq;
 using Amazon;
 
 namespace Spiffy.Monitoring.Aws
@@ -23,8 +25,110 @@ public void Never()
         }
     }
 
+    /// <summary>
+    /// The kinds of message the AWS SDK reports on every call that say nothing a reader can act on.
+    /// Every kind is filtered by default; see <see cref="NoiseFiltersApi"/>.
+    /// </summary>
+    public enum SdkNoise
+    {
+        /// <summary>Reported for all configurations (legacy/standard/etc).</summary>
+        DefaultConfigurationMode,
+
+        /// <summary>Routine DynamoDB usage, once per table description the SDK loads, cached or not.</summary>
+        TableDescription,
+
+        /// <summary>One line per unset variable, on every client construction.</summary>
+        UnsetEnvironmentVariables,
+
+        /// <summary>One per call, restating the SDK's own user agent.</summary>
+        UserAgentHeader,
+
+        /// <summary>Internal buffer growth while (de)serializing.</summary>
+        BufferResizing,
+
+        /// <summary>Internal retry bookkeeping, one per handled error.</summary>
+        RetryBookkeeping,
+
+        /// <summary>Request signing, one per call, carrying the request path.</summary>
+        RequestCanonicalization
+    }
+
+    public class NoiseFiltersApi
+    {
+        // Ordered so Prefixes is deterministic.  A kind can cover more than one prefix -- the
+        // SDK reports canonicalization as both "Single encoded" and "Double encoded".
+        static readonly KeyValuePair<SdkNoise, string[]>[] KnownNoise =
+        {
+            Known(SdkNoise.DefaultConfigurationMode, "Resolved DefaultConfigurationMode for RegionEndpoint"),
+            Known(SdkNoise.TableDescription, "Description for table"),
+            Known(SdkNoise.UnsetEnvironmentVariables, "The environment variable "),
+            Known(SdkNoise.UserAgentHeader, "User-Agent Header"),
+            Known(SdkNoise.BufferResizing, "Resizing buffer"),
+            Known(SdkNoise.RetryBookkeeping, "Retry check: "),
+            Known(SdkNoise.RequestCanonicalization, "Single encoded ", "Double encoded ")
+        };
+
+        static KeyValuePair<SdkNoise, string[]> Known(SdkNoise kind, params string[] prefixes)
+        {
+            return new KeyValuePair<SdkNoise, string[]>(kind, prefixes);
+        }
+
+        readonly HashSet<SdkNoise> _kinds = new HashSet<SdkNoise>(KnownNoise.Select(known => known.Key));
+        readonly List<string> _prefixes = new List<string>();
+
+        // Only Information and Verbose are filtered against these; Warning and above always
+        // reach the log regardless of what's configured here.
+        internal IReadOnlyList<string> Prefixes =>
+            KnownNoise
+                .Where(known => _kinds.Contains(known.Key))
+                .SelectMany(known => known.Value)
+                .Concat(_prefixes)
+                .ToArray();
+
+        /// <summary>
+        /// Also filters <paramref name="kinds"/>, on top of whatever is already filtered.
+        /// </summary>
+        public void Add(params SdkNoise[] kinds)
+        {
+            foreach (var kind in kinds)
+            {
+                _kinds.Add(kind);
+            }
+        }
+
+        /// <summary>
+        /// Also filters messages starting with <paramref name="prefixes"/> -- for noise spiffy
+        /// doesn't know about, which <see cref="SdkNoise"/> can't name.
+        /// </summary>
+        public void Add(params string[] prefixes)
+        {
+            _prefixes.AddRange(prefixes);
+        }
+
+        /// <summary>
+        /// Stops filtering <paramref name="kinds"/>, so those messages are logged again.
+        /// </summary>
+        public void Remove(params SdkNoise[] kinds)
+        {
+            foreach (var kind in kinds)
+            {
+                _kinds.Remove(kind);
+            }
+        }
+
+        /// <summary>
+        /// Filters nothing, so every message the SDK reports is logged.
+        /// </summary>
+        public void Clear()
+        {
+            _kinds.Clear();
+            _prefixes.Clear();
+        }
+    }
+
     public class AwsConfigurationApi
     {
         public ResponseLoggingApi LogResponses { get; } = new ResponseLoggingApi();
+        public NoiseFiltersApi NoiseFilters { get; } = new NoiseFiltersApi();
     }
 }

src/Spiffy.Monitoring.Aws/AwsProvider.cs

@@ -1,5 +1,7 @@
 using System;
+using System.Collections.Generic;
 using System.Diagnostics;
+using System.Linq;
 using Amazon;
 using Spiffy.Monitoring.Config;
 
@@ -9,12 +11,12 @@ public static class AwsProvider
     {
         public static InitializationApi.ProvidersApi Aws(this InitializationApi.ProvidersApi providers, Action<AwsConfigurationApi> configure = null)
         {
-            AWSConfigs.LoggingConfig.LogTo = LoggingOptions.SystemDiagnostics;
-            AWSConfigs.AddTraceListener("Amazon", new AwsEvent());
-
             var config = new AwsConfigurationApi();
             configure?.Invoke(config);
 
+            AWSConfigs.LoggingConfig.LogTo = LoggingOptions.SystemDiagnostics;
+            AWSConfigs.AddTraceListener("Amazon", new AwsEvent(config.NoiseFilters.Prefixes));
+
             switch (config.LogResponses.ResponseLoggingOption)
             {
                 case ResponseLoggingOption.Never:
@@ -31,57 +33,104 @@ public static InitializationApi.ProvidersApi Aws(this InitializationApi.Provider
             return providers;
         }
 
-        class AwsEvent : TraceListener
+        internal class AwsEvent : TraceListener
         {
+            readonly IReadOnlyList<string> _noisePrefixes;
+
+            public AwsEvent(IReadOnlyList<string> noisePrefixes)
+            {
+                _noisePrefixes = noisePrefixes;
+            }
+
+            // TraceData is a System.Diagnostics.TraceListener member, so what's overridden here
+            // is BCL surface -- nothing about it is tied to an SDK version, and one
+            // implementation serves both majors.  Both report exclusively through
+            // TraceSource.TraceData (v3 via InternalSystemDiagnosticsLogger, v4 via
+            // DiagnosticAdaptorLogger), which is where the severity is available;
+            // Write/WriteLine only ever see the flattened string.  Every v4 message lands on
+            // this overload, as do v3's InfoFormat/DebugFormat.
+            public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, object data)
+            {
+                Handle(eventType, data?.ToString(), null);
+            }
+
+            // Only v3 reaches this overload, from Error/Debug, which pass the message and the
+            // exception separately.  v4 accepts an exception and discards it before this point.
+            public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, params object[] data)
+            {
+                if (data == null || data.Length == 0)
+                {
+                    return;
+                }
+                Handle(eventType, data[0]?.ToString(), data.Length > 1 ? data[1] as Exception : null);
+            }
+
             public override void Write(string message)
             {
-                // these messages tend to be useless, e.g.
-                // Message="Amazon Information: 0 : "
+                // headers, e.g. Message="Amazon Information: 0 : "
             }
 
+            // Nothing in the SDK reaches the listener this way today, but a caller that
+            // bypasses TraceData carries no severity, so treat it as informational.
             public override void WriteLine(string message)
             {
-                Handle(message);
+                Handle(TraceEventType.Information, message, null);
             }
 
-            void Handle(string message)
+            void Handle(TraceEventType eventType, string message, Exception exception)
             {
                 if (string.IsNullOrWhiteSpace(message))
                 {
                     return;
                 }
-                if (!IsSdkSpam(message))
+                if (IsNoise(eventType, message))
                 {
-                    using (var context = new EventContext("AwsSdk", "Event"))
-                    {
-                        context["Message"] = message;
+                    return;
+                }
+
+                using (var context = new EventContext("AwsSdk", "Event"))
+                {
+                    context["Message"] = message;
 
-                        // some example exception messages:
-                        // An exception of type HttpErrorResponseException was handled in ErrorHandler...
-                        // UnsupportedLanguagePairException making request TranslateTextRequest...
-                        // An exception of type TimeoutException was handled in ErrorHandler...
-                        if (message.IndexOf("exception", Math.Min(100, message.Length), StringComparison.OrdinalIgnoreCase) != -1)
+                    if (eventType == TraceEventType.Error || eventType == TraceEventType.Critical)
+                    {
+                        if (exception == null)
                         {
                             context.SetToError();
                         }
+                        else
+                        {
+                            // also sets the level to error
+                            context.IncludeException(exception);
+                        }
+                    }
+                    else
+                    {
+                        if (eventType == TraceEventType.Warning)
+                        {
+                            context.SetToWarning();
+                        }
+                        if (exception != null)
+                        {
+                            context.IncludeInformationalException(exception, "Exception");
+                        }
                     }
                 }
             }
 
-            static bool IsSdkSpam(string message)
+            // Severity decides first: only what the SDK reports below Warning is eligible for
+            // prefix matching.
+            bool IsNoise(TraceEventType eventType, string message)
             {
-                // this message happens often and for all configurations (legacy/standard/etc)
-                if (message.StartsWith("Resolved DefaultConfigurationMode for RegionEndpoint"))
-                {
-                    return true;
-                }
-                // this message happens as part of routine DynamoDB usage
-                if (message.StartsWith("Description for table") && message.EndsWith("loaded from SDK Cache"))
+                switch (eventType)
                 {
-                    return true;
+                    case TraceEventType.Critical:
+                    case TraceEventType.Error:
+                    case TraceEventType.Warning:
+                        return false;
+                    default:
+                        return _noisePrefixes.Any(prefix => message.StartsWith(prefix, StringComparison.Ordinal));
                 }
-
-                return false;
             }
 
             public override string Name { get; set; } = nameof(AwsEvent);

src/Spiffy.Monitoring.Aws/Properties/AssemblyInfo.cs

@@ -0,0 +1,3 @@
+using System.Runtime.CompilerServices;
+
+[assembly: InternalsVisibleTo("UnitTests")]

src/Spiffy.Monitoring.Aws/Spiffy.Monitoring.Aws.csproj

@@ -12,7 +12,7 @@
         <PackageReadmeFile>README.md</PackageReadmeFile>
         <PackageLicenseExpression>MIT</PackageLicenseExpression>
         <GeneratePackageOnBuild>True</GeneratePackageOnBuild>
-        <Version>2.0.3</Version>
+        <Version>2.1.0</Version>
         <RootNamespace>Spiffy.Monitoring.Aws</RootNamespace>
     </PropertyGroup>
 

tests/TestConsoleApp/Program.cs

@@ -79,11 +79,20 @@ static void Main(string[] args)
                                 .OverrideValues(OverrideValues)
                             .ToCounter("my_app_my_counter", "Counter Help String");
                         break;
+                    // pass "unfiltered" to see what the default suppression is removing
                     case "aws":
+                        var unfiltered = args.Length > 1 && args[1].Trim().ToLower() == "unfiltered";
                         Configuration.Initialize(spiffy =>
                             spiffy.Providers
                                 .Console()
-                                .Aws(c => c.LogResponses.Always()));
+                                .Aws(c =>
+                                {
+                                    c.LogResponses.Always();
+                                    if (unfiltered)
+                                    {
+                                        c.NoiseFilters.Clear();
+                                    }
+                                }));
                         var id = new AmazonSecurityTokenServiceClient()
                             .GetCallerIdentityAsync(new GetCallerIdentityRequest()).Result;
                         break;