Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add more debug logging where appropriate #138

Merged
merged 5 commits into from
Sep 25, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion samples/JS6.EF/wwwroot/index.html
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@
<body>
<div class="container">
<header class="page-header">
<h1>SPA (.NET 5 host w/ EntityFramework)</h1>
<h1>SPA (w/ EntityFramework)</h1>
</header>

<div class="row">
Expand Down
16 changes: 15 additions & 1 deletion src/Duende.Bff.EntityFramework/Store/UserSessionStore.cs
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,8 @@ public UserSessionStore(IOptions<DataProtectionOptions> options, ISessionDbConte
/// <inheritdoc/>
public async Task CreateUserSessionAsync(UserSession session, CancellationToken cancellationToken)
{
_logger.LogDebug("Creating user session record in store for sub {sub} sid {sid}", session.SubjectId, session.SessionId);

var item = new UserSessionEntity()
{
ApplicationName = _applicationDiscriminator
Expand All @@ -65,6 +67,8 @@ public async Task DeleteUserSessionAsync(string key, CancellationToken cancellat

if (item != null)
{
_logger.LogDebug("Deleting user session record in store for sub {sub} sid {sid}", item.SubjectId, item.SessionId);

_sessionDbContext.UserSessions.Remove(item);
try
{
Expand Down Expand Up @@ -114,6 +118,8 @@ public async Task DeleteUserSessionsAsync(UserSessionsFilter filter, Cancellatio
items = items.Where(x => x.SessionId == filter.SessionId).ToArray();
}

_logger.LogDebug("Deleting {count} user session(s) from store for sub {sub} sid {sid}", items.Length, filter.SubjectId, filter.SessionId);

_sessionDbContext.UserSessions.RemoveRange(items);

try
Expand Down Expand Up @@ -143,6 +149,8 @@ public async Task<UserSession> GetUserSessionAsync(string key, CancellationToken
UserSession result = null;
if (item != null)
{
_logger.LogDebug("Getting user session record from store for sub {sub} sid {sid}", item.SubjectId, item.SessionId);

result = new UserSession();
item.CopyTo(result);
}
Expand Down Expand Up @@ -179,12 +187,16 @@ public async Task<IReadOnlyCollection<UserSession>> GetUserSessionsAsync(UserSes
items = items.Where(x => x.SessionId == filter.SessionId).ToArray();
}

return items.Select(x =>
var results = items.Select(x =>
{
var item = new UserSession();
x.CopyTo(item);
return item;
}).ToArray();

_logger.LogDebug("Getting {count} user session(s) from store for sub {sub} sid {sid}", results.Length, filter.SubjectId, filter.SessionId);

return results;
}

/// <inheritdoc/>
Expand All @@ -194,6 +206,8 @@ public async Task UpdateUserSessionAsync(string key, UserSessionUpdate session,
var item = items.SingleOrDefault(x => x.Key == key && x.ApplicationName == _applicationDiscriminator);
if (item != null)
{
_logger.LogDebug("Updating user session record in store for sub {sub} sid {sid}", item.SubjectId, item.SessionId);

session.CopyTo(item);
await _sessionDbContext.SaveChangesAsync(cancellationToken);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -66,6 +66,8 @@ public class DefaultBackchannelLogoutService : IBackchannelLogoutService
/// <inheritdoc />
public virtual async Task ProcessRequestAsync(HttpContext context)
{
Logger.LogDebug("Processing back-channel logout request");

context.Response.Headers.Add("Cache-Control", "no-cache, no-store");
context.Response.Headers.Add("Pragma", "no-cache");

Expand Down Expand Up @@ -120,8 +122,13 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
var claims = await ValidateJwt(logoutToken);
if (claims == null)
{
Logger.LogDebug("No claims in back-channel JWT");
return null;
}
else
{
Logger.LogTrace("Claims found in back-channel JWT {claims}", claims.Claims);
}

if (claims.FindFirst("sub") == null && claims.FindFirst("sid") == null)
{
Expand Down Expand Up @@ -174,6 +181,7 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
var result = handler.ValidateToken(jwt, parameters);
if (result.IsValid)
{
Logger.LogDebug("Back-channel JWT validation successful");
return result.ClaimsIdentity;
}

Expand Down
16 changes: 14 additions & 2 deletions src/Duende.Bff/EndpointServices/Login/DefaultLoginService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@

using Microsoft.AspNetCore.Authentication;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using System;
using System.Linq;
Expand All @@ -19,26 +20,35 @@ public class DefaultLoginService : ILoginService
/// The BFF options
/// </summary>
protected readonly BffOptions Options;

/// <summary>
/// The return URL validator
/// </summary>
protected readonly IReturnUrlValidator ReturnUrlValidator;

/// <summary>
/// The logger
/// </summary>
protected readonly ILogger Logger;

/// <summary>
/// ctor
/// </summary>
/// <param name="options"></param>
/// <param name="returnUrlValidator"></param>
public DefaultLoginService(IOptions<BffOptions> options, IReturnUrlValidator returnUrlValidator)
/// <param name="logger"></param>
public DefaultLoginService(IOptions<BffOptions> options, IReturnUrlValidator returnUrlValidator, ILogger<DefaultLoginService> logger)
{
Options = options.Value;
ReturnUrlValidator = returnUrlValidator;
Logger = logger;
}

/// <inheritdoc />
public virtual async Task ProcessRequestAsync(HttpContext context)
{
Logger.LogDebug("Processing login request");

context.CheckForBffMiddleware(Options);

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

Logger.LogDebug("Login endpoint triggering Challenge with returnUrl {returnUrl}", returnUrl);

await context.ChallengeAsync(props);
}
}
26 changes: 20 additions & 6 deletions src/Duende.Bff/EndpointServices/Logout/DefaultLogoutService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using IdentityModel;
using Microsoft.AspNetCore.Authentication;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using System;
using System.Linq;
Expand All @@ -30,23 +31,35 @@ public class DefaultLogoutService : ILogoutService
/// The return URL validator
/// </summary>
protected readonly IReturnUrlValidator ReturnUrlValidator;

/// <summary>
/// The logger
/// </summary>
protected readonly ILogger Logger;

/// <summary>
/// Ctor
/// </summary>
/// <param name="options"></param>
/// <param name="authenticationAuthenticationSchemeProviderProvider"></param>
/// <param name="returnUrlValidator"></param>
public DefaultLogoutService(IOptions<BffOptions> options, IAuthenticationSchemeProvider authenticationAuthenticationSchemeProviderProvider, IReturnUrlValidator returnUrlValidator)
/// <param name="logger"></param>
public DefaultLogoutService(IOptions<BffOptions> options,
IAuthenticationSchemeProvider authenticationAuthenticationSchemeProviderProvider,
IReturnUrlValidator returnUrlValidator,
ILogger<DefaultLogoutService> logger)
{
Options = options.Value;
AuthenticationSchemeProvider = authenticationAuthenticationSchemeProviderProvider;
ReturnUrlValidator = returnUrlValidator;
Logger = logger;
}

/// <inheritdoc />
public virtual async Task ProcessRequestAsync(HttpContext context)
{
Logger.LogDebug("Processing logout request");

context.CheckForBffMiddleware(Options);

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

// get rid of local cookie first
var signInScheme = await AuthenticationSchemeProvider.GetDefaultSignInSchemeAsync();
await context.SignOutAsync(signInScheme?.Name);

var returnUrl = context.Request.Query[Constants.RequestParameters.ReturnUrl].FirstOrDefault();

if (!string.IsNullOrWhiteSpace(returnUrl))
{
if (!await ReturnUrlValidator.IsValidAsync(returnUrl))
Expand All @@ -80,6 +88,10 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
}
}

// get rid of local cookie first
var signInScheme = await AuthenticationSchemeProvider.GetDefaultSignInSchemeAsync();
await context.SignOutAsync(signInScheme?.Name);

if (String.IsNullOrWhiteSpace(returnUrl))
{
if (context.Request.PathBase.HasValue)
Expand All @@ -97,6 +109,8 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
RedirectUri = returnUrl
};

Logger.LogDebug("Logout endpoint triggering SignOut with returnUrl {returnUrl}", returnUrl);

// trigger idp logout
await context.SignOutAsync(props);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using IdentityModel;
using Microsoft.AspNetCore.Authentication;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using System.Text;
using System.Threading.Tasks;
Expand All @@ -15,21 +16,33 @@ namespace Duende.Bff;
/// </summary>
public class DefaultSilentLoginCallbackService : ISilentLoginCallbackService
{
private readonly BffOptions _options;
/// <summary>
/// The BFF options
/// </summary>
protected readonly BffOptions Options;

/// <summary>
/// The logger
/// </summary>
protected readonly ILogger Logger;

/// <summary>
/// ctor
/// </summary>
/// <param name="options"></param>
public DefaultSilentLoginCallbackService(IOptions<BffOptions> options)
/// <param name="logger"></param>
public DefaultSilentLoginCallbackService(IOptions<BffOptions> options, ILogger<DefaultSilentLoginCallbackService> logger)
{
_options = options.Value;
Options = options.Value;
Logger = logger;
}

/// <inheritdoc />
public async Task ProcessRequestAsync(HttpContext context)
public virtual async Task ProcessRequestAsync(HttpContext context)
{
context.CheckForBffMiddleware(_options);
Logger.LogDebug("Processing silent login callback request");

context.CheckForBffMiddleware(Options);

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

Logger.LogDebug("Silent login endpoint rendering HTML with JS postMessage to origin {origin} with isLoggedIn {isLoggedIn}", origin, result);

await context.Response.WriteAsync(html, Encoding.UTF8);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@

using Microsoft.AspNetCore.Authentication;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using System.Threading.Tasks;

Expand All @@ -13,24 +14,36 @@ namespace Duende.Bff;
/// </summary>
public class DefaultSilentLoginService : ISilentLoginService
{
private readonly BffOptions _options;
/// <summary>
/// The BFF options
/// </summary>
protected readonly BffOptions Options;

/// <summary>
/// The logger
/// </summary>
protected readonly ILogger Logger;

/// <summary>
/// ctor
/// </summary>
/// <param name="options"></param>
public DefaultSilentLoginService(IOptions<BffOptions> options)
/// <param name="logger"></param>
public DefaultSilentLoginService(IOptions<BffOptions> options, ILogger<DefaultSilentLoginService> logger)
{
_options = options.Value;
Options = options.Value;
Logger = logger;
}

/// <inheritdoc />
public async Task ProcessRequestAsync(HttpContext context)
public virtual async Task ProcessRequestAsync(HttpContext context)
{
context.CheckForBffMiddleware(_options);
Logger.LogDebug("Processing silent login request");

context.CheckForBffMiddleware(Options);

var pathBase = context.Request.PathBase;
var redirectPath = pathBase + _options.SilentLoginCallbackPath;
var redirectPath = pathBase + Options.SilentLoginCallbackPath;

var props = new AuthenticationProperties
{
Expand All @@ -41,6 +54,8 @@ public async Task ProcessRequestAsync(HttpContext context)
},
};

Logger.LogDebug("Silent login endpoint triggering Challenge with returnUrl {redirectUri}", redirectPath);

await context.ChallengeAsync(props);
}
}
6 changes: 6 additions & 0 deletions src/Duende.Bff/EndpointServices/User/DefaultUserService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,8 @@ public DefaultUserService(IOptions<BffOptions> options, ILoggerFactory loggerFac
/// <inheritdoc />
public virtual async Task ProcessRequestAsync(HttpContext context)
{
Logger.LogDebug("Processing user request");

context.CheckForBffMiddleware(Options);

var result = await context.AuthenticateAsync();
Expand All @@ -63,6 +65,8 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
{
context.Response.StatusCode = 401;
}

Logger.LogDebug("User endpoint indicates the user is not logged in, using status code {code}", context.Response.StatusCode);
}
else
{
Expand All @@ -75,6 +79,8 @@ public virtual async Task ProcessRequestAsync(HttpContext context)
context.Response.StatusCode = 200;
context.Response.ContentType = "application/json";
await context.Response.WriteAsync(json, Encoding.UTF8);

Logger.LogTrace("User endpoint indicates the user is logged in with claims {claims}", claims);
}
}

Expand Down
Loading