Search code examples
c#openid-connectasp.net-core-identity

Is it possible to trace what the middleware is doing in MS Identity/OpenID Connect?


I'm trying to understand how to to authenticate to login.microsoftonline.com in C#.

I registered a test app on portal.azure.com, and used their "Quickstart" to auto-generate an example ASP.Net Core 3.1 project. I got these redirect URIs:

   https://localhost:44321/signin-oidc
   https://localhost:44321/
   https://localhost:44368/
   https://localhost:5001

The auto-generated, ASP.Net Core 3.1 project compiled and ran like a charm. I was able to authenticate.

Next, I tried copying/pasting from the auto-generated code into a separate, ASP.Net Core 5 project where I'm successfully using ASP.Net Core Identity to authenticate to a "local account" (an ASP.Net Core Identity database) and to Google (OAuth2 authentication, which is what I'm TRYING to accomplish with Microsoft!)

It fails with this unhelpful message in the web browser:

"Error loading external login information"

Q: How can I "trace" what the MS Identity and/or OpenID Connect middleware is doing "under the covers"?

Q: Is there any way for me to enable "verbose logging"?

Here's the Startup.cs in the failing example:

using Microsoft.AspNetCore.Authentication.OpenIdConnect;
using Microsoft.AspNetCore.Authorization;
...
using Microsoft.AspNetCore.Identity;
using Microsoft.AspNetCore.Mvc.Authorization;
...
using Microsoft.Identity.Web;
using Microsoft.Identity.Web.UI;
...
        public void ConfigureServices(IServiceCollection services) {
            // MS Identity Store: This all works, independent of the OpenID Connect problem...
            services.AddDbContext<ApplicationDbContext>(options =>
                options.UseSqlServer(
                    Configuration.GetConnectionString("DefaultConnection")
            ));
            services.AddDatabaseDeveloperPageExceptionFilter();
            services.AddDefaultIdentity<IdentityUser>(options => options.SignIn.RequireConfirmedAccount = true)
                .AddEntityFrameworkStores<ApplicationDbContext>();

            // Known-good "AzureId" copied from working example into appsettings.json
            services.AddAuthentication(OpenIdConnectDefaults.AuthenticationScheme)
                .AddMicrosoftIdentityWebApp(Configuration.GetSection("AzureAd"));

            services.AddControllersWithViews(options =>
            {
                var policy = new AuthorizationPolicyBuilder()
                    .RequireAuthenticatedUser()
                    .Build();
                options.Filters.Add(new AuthorizeFilter(policy));
            });
            services.AddRazorPages()
                 .AddMicrosoftIdentityUI();
                 ...
        public void Configure(IApplicationBuilder app, IWebHostEnvironment env) {
            ...
            app.UseHttpsRedirection();
            app.UseStaticFiles();
            app.UseRouting();

            app.UseAuthentication();
            app.UseAuthorization();

Solution

  • OK, I found at least one alternative:

    • I happen to be using the ASP.Net Core Identity Nuget packages (e.g. Microsoft.Identity.Web, etc.) in my project.
    • They have built-in logging. All the stuff I'm looking for is available at the "Information" log level.
    • By default, this logging is ONLY visible if I run the program from the dotnet CLI (vs. running with the IIS Express debugger in MSVS).
    • Also needed to enable PII to see all the details I needed.

    appsettings.json

    "Logging": {
        "LogLevel": {
          "Default": "Information",
          "Microsoft": "Warning",
          "Microsoft.Hosting.Lifetime": "Information",
          "Microsoft.IdentityModel": "Information"
        }
    

    Startup.cs

    public void ConfigureServices(IServiceCollection services)
    {
        IdentityModelEventSource.ShowPII = true;  // Enable PII logging
        services.AddAuthentication(OpenIdConnectDefaults.AuthenticationScheme)
            .AddMicrosoftIdentityWebApp(Configuration.GetSection("AzureAd"));
        ...
    

    Example MS logging

    dotnet run
    Building...
    info: Microsoft.Hosting.Lifetime[0]
          Now listening on: https://localhost:44321
    ...
    info: Microsoft.IdentityModel.LoggingExtensions.IdentityLoggerAdapter[0]
          Microsoft.IdentityModel Version: 6.25.0.0. Date 11/25/2022 20:10:10. PII logging is ON, do not use in production. See https://aka.ms/IdentityModel/PII for details.
          IDX10242: Security token: 'eyJ0eXA*dENQ' has a valid signature.
    info: Microsoft.IdentityModel.LoggingExtensions.IdentityLoggerAdapter[0]
          IDX10239: Lifetime of the token is valid.
    info: Microsoft.IdentityModel.LoggingExtensions.IdentityLoggerAdapter[0]
          IDX10234: Audience Validated.Audience: '4ec8e*9a'
    info: Microsoft.IdentityModel.LoggingExtensions.IdentityLoggerAdapter[0]
          IDX10245: Creating claims identity from the validated token: '{"typ":"JWT","alg":"RS256","kid":"bW8*4"}.{"ver":"2.0","iss":"https://login.microsoftonline.com/91880*dad/v2.0","sub":"AAAA*LX_8","aud":"4ec8e482-8df2-4e90-bfec-4aafb846c99a","exp":1669493410,"iat":1669406710,"nbf":1669406710,"name":"***,"preferred_username":"***","oid":"00000...e3d","tid":"9188...ad","nonce":"6380*0.YjgzZ*U0","aio":"DXF*Lo$"}'.
    info: Microsoft.IdentityModel.LoggingExtensions.IdentityLoggerAdapter[0]
          IDX10241: Security token validated. token: 'eyJ0e*ENQ'.
    ...