Skip to content
This repository was archived by the owner on Jan 24, 2025. It is now read-only.

Commit 1316f1c

Browse files
leastprivilegeleastprivilege
authored
Merge pull request #138 from DuendeSoftware/brock/logging
Add more debug logging where appropriate
2 parents ee9be8b + f009311 commit 1316f1c

File tree

10 files changed

+112
-30
lines changed

10 files changed

+112
-30
lines changed

‎samples/JS6.EF/wwwroot/index.html

+1-1
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@
99
<body>
1010
<div class="container">
1111
<header class="page-header">
12-
<h1>SPA (.NET 5 host w/ EntityFramework)</h1>
12+
<h1>SPA (w/ EntityFramework)</h1>
1313
</header>
1414

1515
<div class="row">

‎src/Duende.Bff.EntityFramework/Store/UserSessionStore.cs

+15-1
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,8 @@ public UserSessionStore(IOptions<DataProtectionOptions> options, ISessionDbConte
4040
/// <inheritdoc/>
4141
public async Task CreateUserSessionAsync(UserSession session, CancellationToken cancellationToken)
4242
{
43+
_logger.LogDebug("Creating user session record in store for sub {sub} sid {sid}", session.SubjectId, session.SessionId);
44+
4345
var item = new UserSessionEntity()
4446
{
4547
ApplicationName = _applicationDiscriminator
@@ -65,6 +67,8 @@ public async Task DeleteUserSessionAsync(string key, CancellationToken cancellat
6567

6668
if (item != null)
6769
{
70+
_logger.LogDebug("Deleting user session record in store for sub {sub} sid {sid}", item.SubjectId, item.SessionId);
71+
6872
_sessionDbContext.UserSessions.Remove(item);
6973
try
7074
{
@@ -114,6 +118,8 @@ public async Task DeleteUserSessionsAsync(UserSessionsFilter filter, Cancellatio
114118
items = items.Where(x => x.SessionId == filter.SessionId).ToArray();
115119
}
116120

121+
_logger.LogDebug("Deleting {count} user session(s) from store for sub {sub} sid {sid}", items.Length, filter.SubjectId, filter.SessionId);
122+
117123
_sessionDbContext.UserSessions.RemoveRange(items);
118124

119125
try
@@ -143,6 +149,8 @@ public async Task<UserSession> GetUserSessionAsync(string key, CancellationToken
143149
UserSession result = null;
144150
if (item != null)
145151
{
152+
_logger.LogDebug("Getting user session record from store for sub {sub} sid {sid}", item.SubjectId, item.SessionId);
153+
146154
result = new UserSession();
147155
item.CopyTo(result);
148156
}
@@ -179,12 +187,16 @@ public async Task<IReadOnlyCollection<UserSession>> GetUserSessionsAsync(UserSes
179187
items = items.Where(x => x.SessionId == filter.SessionId).ToArray();
180188
}
181189

182-
return items.Select(x =>
190+
var results = items.Select(x =>
183191
{
184192
var item = new UserSession();
185193
x.CopyTo(item);
186194
return item;
187195
}).ToArray();
196+
197+
_logger.LogDebug("Getting {count} user session(s) from store for sub {sub} sid {sid}", results.Length, filter.SubjectId, filter.SessionId);
198+
199+
return results;
188200
}
189201

190202
/// <inheritdoc/>
@@ -194,6 +206,8 @@ public async Task UpdateUserSessionAsync(string key, UserSessionUpdate session,
194206
var item = items.SingleOrDefault(x => x.Key == key && x.ApplicationName == _applicationDiscriminator);
195207
if (item != null)
196208
{
209+
_logger.LogDebug("Updating user session record in store for sub {sub} sid {sid}", item.SubjectId, item.SessionId);
210+
197211
session.CopyTo(item);
198212
await _sessionDbContext.SaveChangesAsync(cancellationToken);
199213
}

‎src/Duende.Bff/EndpointServices/BackchannelLogout/DefaultBackchannelLogoutService.cs

+8
Original file line numberDiff line numberDiff line change
@@ -66,6 +66,8 @@ public DefaultBackchannelLogoutService(
6666
/// <inheritdoc />
6767
public virtual async Task ProcessRequestAsync(HttpContext context)
6868
{
69+
Logger.LogDebug("Processing back-channel logout request");
70+
6971
context.Response.Headers.Add("Cache-Control", "no-cache, no-store");
7072
context.Response.Headers.Add("Pragma", "no-cache");
7173

@@ -120,8 +122,13 @@ await UserSession.RevokeSessionsAsync(new UserSessionsFilter
120122
var claims = await ValidateJwt(logoutToken);
121123
if (claims == null)
122124
{
125+
Logger.LogDebug("No claims in back-channel JWT");
123126
return null;
124127
}
128+
else
129+
{
130+
Logger.LogTrace("Claims found in back-channel JWT {claims}", claims.Claims);
131+
}
125132

126133
if (claims.FindFirst("sub") == null && claims.FindFirst("sid") == null)
127134
{
@@ -174,6 +181,7 @@ await UserSession.RevokeSessionsAsync(new UserSessionsFilter
174181
var result = handler.ValidateToken(jwt, parameters);
175182
if (result.IsValid)
176183
{
184+
Logger.LogDebug("Back-channel JWT validation successful");
177185
return result.ClaimsIdentity;
178186
}
179187

‎src/Duende.Bff/EndpointServices/Login/DefaultLoginService.cs

+14-2
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33

44
using Microsoft.AspNetCore.Authentication;
55
using Microsoft.AspNetCore.Http;
6+
using Microsoft.Extensions.Logging;
67
using Microsoft.Extensions.Options;
78
using System;
89
using System.Linq;
@@ -19,26 +20,35 @@ public class DefaultLoginService : ILoginService
1920
/// The BFF options
2021
/// </summary>
2122
protected readonly BffOptions Options;
22-
23+
2324
/// <summary>
2425
/// The return URL validator
2526
/// </summary>
2627
protected readonly IReturnUrlValidator ReturnUrlValidator;
28+
29+
/// <summary>
30+
/// The logger
31+
/// </summary>
32+
protected readonly ILogger Logger;
2733

2834
/// <summary>
2935
/// ctor
3036
/// </summary>
3137
/// <param name="options"></param>
3238
/// <param name="returnUrlValidator"></param>
33-
public DefaultLoginService(IOptions<BffOptions> options, IReturnUrlValidator returnUrlValidator)
39+
/// <param name="logger"></param>
40+
public DefaultLoginService(IOptions<BffOptions> options, IReturnUrlValidator returnUrlValidator, ILogger<DefaultLoginService> logger)
3441
{
3542
Options = options.Value;
3643
ReturnUrlValidator = returnUrlValidator;
44+
Logger = logger;
3745
}
3846

3947
/// <inheritdoc />
4048
public virtual async Task ProcessRequestAsync(HttpContext context)
4149
{
50+
Logger.LogDebug("Processing login request");
51+
4252
context.CheckForBffMiddleware(Options);
4353

4454
var returnUrl = context.Request.Query[Constants.RequestParameters.ReturnUrl].FirstOrDefault();
@@ -68,6 +78,8 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
6878
RedirectUri = returnUrl
6979
};
7080

81+
Logger.LogDebug("Login endpoint triggering Challenge with returnUrl {returnUrl}", returnUrl);
82+
7183
await context.ChallengeAsync(props);
7284
}
7385
}

‎src/Duende.Bff/EndpointServices/Logout/DefaultLogoutService.cs

+20-6
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
using IdentityModel;
55
using Microsoft.AspNetCore.Authentication;
66
using Microsoft.AspNetCore.Http;
7+
using Microsoft.Extensions.Logging;
78
using Microsoft.Extensions.Options;
89
using System;
910
using System.Linq;
@@ -30,23 +31,35 @@ public class DefaultLogoutService : ILogoutService
3031
/// The return URL validator
3132
/// </summary>
3233
protected readonly IReturnUrlValidator ReturnUrlValidator;
34+
35+
/// <summary>
36+
/// The logger
37+
/// </summary>
38+
protected readonly ILogger Logger;
3339

3440
/// <summary>
3541
/// Ctor
3642
/// </summary>
3743
/// <param name="options"></param>
3844
/// <param name="authenticationAuthenticationSchemeProviderProvider"></param>
3945
/// <param name="returnUrlValidator"></param>
40-
public DefaultLogoutService(IOptions<BffOptions> options, IAuthenticationSchemeProvider authenticationAuthenticationSchemeProviderProvider, IReturnUrlValidator returnUrlValidator)
46+
/// <param name="logger"></param>
47+
public DefaultLogoutService(IOptions<BffOptions> options,
48+
IAuthenticationSchemeProvider authenticationAuthenticationSchemeProviderProvider,
49+
IReturnUrlValidator returnUrlValidator,
50+
ILogger<DefaultLogoutService> logger)
4151
{
4252
Options = options.Value;
4353
AuthenticationSchemeProvider = authenticationAuthenticationSchemeProviderProvider;
4454
ReturnUrlValidator = returnUrlValidator;
55+
Logger = logger;
4556
}
4657

4758
/// <inheritdoc />
4859
public virtual async Task ProcessRequestAsync(HttpContext context)
4960
{
61+
Logger.LogDebug("Processing logout request");
62+
5063
context.CheckForBffMiddleware(Options);
5164

5265
var result = await context.AuthenticateAsync();
@@ -66,12 +79,7 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
6679
}
6780
}
6881

69-
// get rid of local cookie first
70-
var signInScheme = await AuthenticationSchemeProvider.GetDefaultSignInSchemeAsync();
71-
await context.SignOutAsync(signInScheme?.Name);
72-
7382
var returnUrl = context.Request.Query[Constants.RequestParameters.ReturnUrl].FirstOrDefault();
74-
7583
if (!string.IsNullOrWhiteSpace(returnUrl))
7684
{
7785
if (!await ReturnUrlValidator.IsValidAsync(returnUrl))
@@ -80,6 +88,10 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
8088
}
8189
}
8290

91+
// get rid of local cookie first
92+
var signInScheme = await AuthenticationSchemeProvider.GetDefaultSignInSchemeAsync();
93+
await context.SignOutAsync(signInScheme?.Name);
94+
8395
if (String.IsNullOrWhiteSpace(returnUrl))
8496
{
8597
if (context.Request.PathBase.HasValue)
@@ -97,6 +109,8 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
97109
RedirectUri = returnUrl
98110
};
99111

112+
Logger.LogDebug("Logout endpoint triggering SignOut with returnUrl {returnUrl}", returnUrl);
113+
100114
// trigger idp logout
101115
await context.SignOutAsync(props);
102116
}

‎src/Duende.Bff/EndpointServices/SilentLogin/DefaultSilentLoginCallbackService.cs

+20-5
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
using IdentityModel;
55
using Microsoft.AspNetCore.Authentication;
66
using Microsoft.AspNetCore.Http;
7+
using Microsoft.Extensions.Logging;
78
using Microsoft.Extensions.Options;
89
using System.Text;
910
using System.Threading.Tasks;
@@ -15,21 +16,33 @@ namespace Duende.Bff;
1516
/// </summary>
1617
public class DefaultSilentLoginCallbackService : ISilentLoginCallbackService
1718
{
18-
private readonly BffOptions _options;
19+
/// <summary>
20+
/// The BFF options
21+
/// </summary>
22+
protected readonly BffOptions Options;
23+
24+
/// <summary>
25+
/// The logger
26+
/// </summary>
27+
protected readonly ILogger Logger;
1928

2029
/// <summary>
2130
/// ctor
2231
/// </summary>
2332
/// <param name="options"></param>
24-
public DefaultSilentLoginCallbackService(IOptions<BffOptions> options)
33+
/// <param name="logger"></param>
34+
public DefaultSilentLoginCallbackService(IOptions<BffOptions> options, ILogger<DefaultSilentLoginCallbackService> logger)
2535
{
26-
_options = options.Value;
36+
Options = options.Value;
37+
Logger = logger;
2738
}
2839

2940
/// <inheritdoc />
30-
public async Task ProcessRequestAsync(HttpContext context)
41+
public virtual async Task ProcessRequestAsync(HttpContext context)
3142
{
32-
context.CheckForBffMiddleware(_options);
43+
Logger.LogDebug("Processing silent login callback request");
44+
45+
context.CheckForBffMiddleware(Options);
3346

3447
var result = (await context.AuthenticateAsync()).Succeeded ? "true" : "false";
3548
var json = $"{{source:'bff-silent-login', isLoggedIn:{result}}}";
@@ -46,6 +59,8 @@ public async Task ProcessRequestAsync(HttpContext context)
4659
context.Response.Headers["Cache-Control"] = "no-store, no-cache, max-age=0";
4760
context.Response.Headers["Pragma"] = "no-cache";
4861

62+
Logger.LogDebug("Silent login endpoint rendering HTML with JS postMessage to origin {origin} with isLoggedIn {isLoggedIn}", origin, result);
63+
4964
await context.Response.WriteAsync(html, Encoding.UTF8);
5065
}
5166
}

‎src/Duende.Bff/EndpointServices/SilentLogin/DefaultSilentLoginService.cs

+21-6
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33

44
using Microsoft.AspNetCore.Authentication;
55
using Microsoft.AspNetCore.Http;
6+
using Microsoft.Extensions.Logging;
67
using Microsoft.Extensions.Options;
78
using System.Threading.Tasks;
89

@@ -13,24 +14,36 @@ namespace Duende.Bff;
1314
/// </summary>
1415
public class DefaultSilentLoginService : ISilentLoginService
1516
{
16-
private readonly BffOptions _options;
17+
/// <summary>
18+
/// The BFF options
19+
/// </summary>
20+
protected readonly BffOptions Options;
21+
22+
/// <summary>
23+
/// The logger
24+
/// </summary>
25+
protected readonly ILogger Logger;
1726

1827
/// <summary>
1928
/// ctor
2029
/// </summary>
2130
/// <param name="options"></param>
22-
public DefaultSilentLoginService(IOptions<BffOptions> options)
31+
/// <param name="logger"></param>
32+
public DefaultSilentLoginService(IOptions<BffOptions> options, ILogger<DefaultSilentLoginService> logger)
2333
{
24-
_options = options.Value;
34+
Options = options.Value;
35+
Logger = logger;
2536
}
2637

2738
/// <inheritdoc />
28-
public async Task ProcessRequestAsync(HttpContext context)
39+
public virtual async Task ProcessRequestAsync(HttpContext context)
2940
{
30-
context.CheckForBffMiddleware(_options);
41+
Logger.LogDebug("Processing silent login request");
42+
43+
context.CheckForBffMiddleware(Options);
3144

3245
var pathBase = context.Request.PathBase;
33-
var redirectPath = pathBase + _options.SilentLoginCallbackPath;
46+
var redirectPath = pathBase + Options.SilentLoginCallbackPath;
3447

3548
var props = new AuthenticationProperties
3649
{
@@ -41,6 +54,8 @@ public async Task ProcessRequestAsync(HttpContext context)
4154
},
4255
};
4356

57+
Logger.LogDebug("Silent login endpoint triggering Challenge with returnUrl {redirectUri}", redirectPath);
58+
4459
await context.ChallengeAsync(props);
4560
}
4661
}

‎src/Duende.Bff/EndpointServices/User/DefaultUserService.cs

+6
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,8 @@ public DefaultUserService(IOptions<BffOptions> options, ILoggerFactory loggerFac
4747
/// <inheritdoc />
4848
public virtual async Task ProcessRequestAsync(HttpContext context)
4949
{
50+
Logger.LogDebug("Processing user request");
51+
5052
context.CheckForBffMiddleware(Options);
5153

5254
var result = await context.AuthenticateAsync();
@@ -63,6 +65,8 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
6365
{
6466
context.Response.StatusCode = 401;
6567
}
68+
69+
Logger.LogDebug("User endpoint indicates the user is not logged in, using status code {code}", context.Response.StatusCode);
6670
}
6771
else
6872
{
@@ -75,6 +79,8 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
7579
context.Response.StatusCode = 200;
7680
context.Response.ContentType = "application/json";
7781
await context.Response.WriteAsync(json, Encoding.UTF8);
82+
83+
Logger.LogTrace("User endpoint indicates the user is logged in with claims {claims}", claims);
7884
}
7985
}
8086

0 commit comments

Comments
 (0)