Logging improvements

- Log detected replays at information level
- Use activities instead of debug level messages saying that a method was invoked

aspnetcore-authentication-jwtbearer/src/AspNetCore.Authentication.JwtBearer/DPoP/DPoPJwtBearerEvents.cs

@@ -39,7 +39,7 @@ internal class DPoPJwtBearerEvents
     /// </summary>
     public Task MessageReceived(MessageReceivedContext context)
     {
-        _logger.LogDebug("MessageReceived invoked in a JWT bearer authentication scheme using DPoP");
+        using var activity = Tracing.ActivitySource.StartActivity("DPoPJwtBearerEvents.MessageReceived");
 
         var dpopOptions = _optionsMonitor.Get(context.Scheme.Name);
 
@@ -62,7 +62,7 @@ internal class DPoPJwtBearerEvents
     /// </summary>
     public async Task TokenValidated(TokenValidatedContext context)
     {
-        _logger.LogDebug("TokenValidated invoked in a JWT bearer authentication scheme using DPoP");
+        using var activity = Tracing.ActivitySource.StartActivity("DPoPJwtBearerEvents.TokenValidated");
 
         var dPoPOptions = _optionsMonitor.Get(context.Scheme.Name);
 
@@ -135,7 +135,7 @@ internal class DPoPJwtBearerEvents
     /// <summary>
     /// Checks if the HTTP authorization header's 'scheme' is DPoP.
     /// </summary>
-    protected static bool IsDPoPAuthorizationScheme(HttpRequest request)
+    private static bool IsDPoPAuthorizationScheme(HttpRequest request)
     {
         var authz = request.Headers.Authorization.FirstOrDefault();
         return authz?.StartsWith(DPoPPrefix, StringComparison.OrdinalIgnoreCase) == true;
@@ -144,7 +144,7 @@ internal class DPoPJwtBearerEvents
     /// <summary>
     /// Attempts to retrieve a DPoP access token from an <see cref="HttpRequest"/>.
     /// </summary>
-    public bool TryGetDPoPAccessToken(HttpRequest request,
+    private bool TryGetDPoPAccessToken(HttpRequest request,
         int maxLength,
         [NotNullWhen(true)] out string? token)
     {
@@ -172,7 +172,8 @@ internal class DPoPJwtBearerEvents
     /// </summary>
     public Task Challenge(JwtBearerChallengeContext context)
     {
-        _logger.LogDebug("Challenge invoked in a JWT bearer authentication scheme using DPoP");
+        using var activity = Tracing.ActivitySource.StartActivity("DPoPJwtBearerEvents.Challenge");
+
         var dPoPOptions = _optionsMonitor.Get(context.Scheme.Name);
 
         if (!dPoPOptions.AllowBearerTokens)

aspnetcore-authentication-jwtbearer/src/AspNetCore.Authentication.JwtBearer/DPoP/DPoPProofValidator.cs

@@ -72,13 +72,14 @@ internal class DPoPProofValidator : IDPoPProofValidator
     /// </summary>
     public async Task<DPoPProofValidationResult> Validate(DPoPProofValidationContext context, CancellationToken cancellationToken = default)
     {
-        Logger.LogDebug("Validating DPoP proof token");
+        using var activity = Tracing.ActivitySource.StartActivity("DPoPProofValidator.Validate");
+
         var result = new DPoPProofValidationResult();
 
         if (string.IsNullOrEmpty(context.ProofToken))
         {
             Logger.LogDebug("Missing DPoP proof value");
-            result.SetError("Missing DPoP proof value", OidcConstants.TokenErrors.InvalidRequest);
+            result.SetError("Missing DPoP proof token.", OidcConstants.TokenErrors.InvalidRequest);
             return result;
         }
 
@@ -115,7 +116,7 @@ internal class DPoPProofValidator : IDPoPProofValidator
         await ValidateReplay(context, result, cancellationToken);
         if (result.IsError)
         {
-            Logger.LogDebug("Detected replay of DPoP proof token");
+            Logger.LogInformation("Detected replay of DPoP proof token");
         }
 
         Logger.LogDebug("Successfully validated DPoP proof token");

aspnetcore-authentication-jwtbearer/src/AspNetCore.Authentication.JwtBearer/DPoP/ReplayCache.cs

@@ -21,6 +21,8 @@ internal class ReplayCache : IReplayCache
 
     public async Task Add(string handle, TimeSpan expiration, CancellationToken ct)
     {
+        using var activity = Tracing.ActivitySource.StartActivity("ReplayCache.Add");
+
         var options = new HybridCacheEntryOptions
         {
             Expiration = expiration
@@ -36,10 +38,15 @@ internal class ReplayCache : IReplayCache
                 | HybridCacheEntryFlags.DisableUnderlyingData
     };
 
-    public async Task<bool> Exists(string handle, CancellationToken ct) => await _cache.GetOrCreateAsync<bool>(
+    public async Task<bool> Exists(string handle, CancellationToken ct)
+    {
+        using var activity = Tracing.ActivitySource.StartActivity("ReplayCache.Exists");
+
+        return await _cache.GetOrCreateAsync<bool>(
             Prefix + handle,
             // The factory will never be invoked because the ReadOnlyEntryOptions set the DisableUnderlyingData flag
             cancel => throw new InvalidOperationException("Can't Happen"),
             ReadOnlyEntryOptions,
             cancellationToken: ct);
+    }
 }

aspnetcore-authentication-jwtbearer/src/AspNetCore.Authentication.JwtBearer/DPoP/Tracing.cs

@@ -0,0 +1,19 @@
+// Copyright (c) Duende Software. All rights reserved.
+// See LICENSE in the project root for license information.
+
+using System.Diagnostics;
+
+namespace Duende.AspNetCore.Authentication.JwtBearer.DPoP;
+
+internal static class Tracing
+{
+    private static readonly Version? AssemblyVersion = typeof(Tracing).Assembly.GetName().Version;
+
+    public static string ServiceVersion =>
+        AssemblyVersion != null ? $"{AssemblyVersion.Major}.{AssemblyVersion.Minor}.{AssemblyVersion.Build}" :
+            "Unknown Version";
+
+    public static ActivitySource ActivitySource { get; } = new(
+        "Duende.AspNetCore.Authentication.JwtBearer",
+        ServiceVersion);
+}

identity-server/aspire/ServiceDefaults/Extensions.cs

@@ -62,6 +62,7 @@ public static class Extensions
                     .AddSource(IdentityServerConstants.Tracing.Services)
                     .AddSource(IdentityServerConstants.Tracing.Stores)
                     .AddSource(IdentityServerConstants.Tracing.Validation)
+                    .AddSource("Duende.AspNetCore.Authentication.JwtBearer")
                     .AddAspNetCoreInstrumentation()
                     .AddHttpClientInstrumentation();
             });

identity-server/clients/src/APIs/DPoPApi/DPoPApi.csproj

@@ -1,12 +1,12 @@
 <Project Sdk="Microsoft.NET.Sdk.Web">
 
   <ItemGroup>
+    <ProjectReference Include="..\..\..\..\..\aspnetcore-authentication-jwtbearer\src\AspNetCore.Authentication.JwtBearer\AspNetCore.Authentication.JwtBearer.csproj" />
     <ProjectReference Include="..\..\..\..\aspire\ServiceDefaults\ServiceDefaults.csproj" />
     <ProjectReference Include="..\..\Constants\Constants.csproj" />
   </ItemGroup>
 
   <ItemGroup>
-    <PackageReference Include="Duende.AspNetCore.Authentication.JwtBearer" />
     <PackageReference Include="Serilog.AspNetCore" />
   </ItemGroup>
 

identity-server/clients/src/APIs/DPoPApi/Program.cs

@@ -32,7 +32,8 @@ try
 
     builder.Services.ConfigureDPoPTokensForScheme("token", options =>
     {
-        options.TokenMode = DPoPMode.DPoPAndBearer;
+        options.AllowBearerTokens = true;
+        options.EnableReplayDetection = true;
     });
 
     var app = builder.Build();