Add six-month domain and broker monitoring

2026-09-04 16:57:34 -06:00
parent f2a40f051b
commit dcbf5e87e3
20 changed files with 998 additions and 28 deletions
@@ -0,0 +1,24 @@
+namespace SGU.AuthBroker;
+
+internal static class BrokerEventIds
+{
+    internal static readonly EventId BrokerStarted = new(900, nameof(BrokerStarted));
+    internal static readonly EventId AuthenticationAuthorized = new(1000, nameof(AuthenticationAuthorized));
+    internal static readonly EventId AuthenticationRejected = new(1001, nameof(AuthenticationRejected));
+    internal static readonly EventId AuthenticationUnavailable = new(1002, nameof(AuthenticationUnavailable));
+    internal static readonly EventId AuthenticationInvalidRequest = new(1003, nameof(AuthenticationInvalidRequest));
+
+    internal static readonly EventId SguAuthenticationAccepted = new(1100, nameof(SguAuthenticationAccepted));
+    internal static readonly EventId SguAuthenticationTimeout = new(1101, nameof(SguAuthenticationTimeout));
+    internal static readonly EventId SguAuthenticationNetworkFailure = new(1102, nameof(SguAuthenticationNetworkFailure));
+
+    internal static readonly EventId ProfileEnrichmentCompleted = new(1200, nameof(ProfileEnrichmentCompleted));
+    internal static readonly EventId ProfileHtmlUnexpected = new(1201, nameof(ProfileHtmlUnexpected));
+    internal static readonly EventId ProfileEnrichmentTimeout = new(1202, nameof(ProfileEnrichmentTimeout));
+    internal static readonly EventId ProfileEnrichmentFailure = new(1203, nameof(ProfileEnrichmentFailure));
+    internal static readonly EventId ProfilePageUnavailable = new(1204, nameof(ProfilePageUnavailable));
+
+    internal static readonly EventId DirectorySynchronizationFailure = new(1300, nameof(DirectorySynchronizationFailure));
+    internal static readonly EventId DirectoryOptionalMetadataFailure = new(1301, nameof(DirectoryOptionalMetadataFailure));
+    internal static readonly EventId DirectoryGroupMembershipFailure = new(1302, nameof(DirectoryGroupMembershipFailure));
+}
@@ -1,7 +1,9 @@
+using System.Diagnostics;
 using System.Net.Security;
 using System.Security.Cryptography.X509Certificates;
 using System.Threading.RateLimiting;
 using Microsoft.AspNetCore.Server.Kestrel.Https;
+using SGU.AuthBroker;
 using SGU.AuthBroker.Contracts;
 using SGU.AuthBroker.Core.Authentication;
 using SGU.AuthBroker.Core.Directory;
@@ -10,6 +12,16 @@ using SGU.AuthBroker.Services;

 WebApplicationBuilder builder = WebApplication.CreateBuilder(args);
 builder.Host.UseWindowsService(options => options.ServiceName = "SGU Authentication Broker");
+if (builder.Configuration.GetValue("Broker:Diagnostics:UseDedicatedEventLog", false))
+{
+    builder.Logging.ClearProviders();
+    builder.Logging.AddEventLog(settings =>
+    {
+        settings.LogName = "SGU Auth Broker";
+        settings.SourceName = "SGU.AuthBroker.Operational";
+        settings.Filter = (_, level) => level >= LogLevel.Information;
+    });
+}

 BrokerOptions brokerOptions = builder.Configuration
    .GetSection(BrokerOptions.SectionName)
@@ -56,6 +68,12 @@ builder.Services.AddRateLimiter(options =>
 });

 WebApplication app = builder.Build();
+ILogger auditLogger = app.Services.GetRequiredService<ILoggerFactory>()
+    .CreateLogger("SGU.AuthBroker.Audit");
+auditLogger.LogInformation(
+    BrokerEventIds.BrokerStarted,
+    "SGU Authentication Broker started with dedicated operational diagnostics enabled={DedicatedDiagnosticsEnabled}.",
+    builder.Configuration.GetValue("Broker:Diagnostics:UseDedicatedEventLog", false));
 app.UseRateLimiter();
 app.Use(async (context, next) =>
 {
@@ -75,16 +93,58 @@ app.MapPost("/v1/authenticate", async (
 {
    if (string.IsNullOrWhiteSpace(request.Password) || request.Password.Length > 256)
    {
+        auditLogger.LogInformation(
+            BrokerEventIds.AuthenticationInvalidRequest,
+            "Authentication request rejected before validation for {InstitutionalUser}: password was missing or outside the supported length.",
+            SafeUserName(request.Clave));
        request.ReleasePasswordReference();
        return Results.BadRequest(new ErrorResponse("MISSING_PASSWORD", "La contraseña es requerida."));
    }

+    Stopwatch elapsed = Stopwatch.StartNew();
    try
    {
        AuthenticationFlowResult result = await workflow
            .AuthenticateAsync(request.Clave, request.Password, cancellationToken)
            .ConfigureAwait(false);

+        string institutionalUser = result.Identity?.UserName ?? SafeUserName(request.Clave);
+        switch (result.Outcome)
+        {
+            case AuthenticationFlowOutcome.Authorized:
+                auditLogger.LogInformation(
+                    BrokerEventIds.AuthenticationAuthorized,
+                    "Authentication completed for {InstitutionalUser} with role {Role} in {ElapsedMilliseconds} ms. AD created={Created}; moved={Moved}.",
+                    institutionalUser,
+                    result.Identity!.Role,
+                    elapsed.ElapsedMilliseconds,
+                    result.Directory!.Created,
+                    result.Directory.Moved);
+                break;
+            case AuthenticationFlowOutcome.InvalidCredentials:
+                auditLogger.LogInformation(
+                    BrokerEventIds.AuthenticationRejected,
+                    "Authentication was rejected for {InstitutionalUser} with code {ErrorCode} after {ElapsedMilliseconds} ms.",
+                    institutionalUser,
+                    result.ErrorCode,
+                    elapsed.ElapsedMilliseconds);
+                break;
+            case AuthenticationFlowOutcome.Unavailable:
+                auditLogger.LogWarning(
+                    BrokerEventIds.AuthenticationUnavailable,
+                    "Authentication was unavailable for {InstitutionalUser} with code {ErrorCode} after {ElapsedMilliseconds} ms.",
+                    institutionalUser,
+                    result.ErrorCode,
+                    elapsed.ElapsedMilliseconds);
+                break;
+            default:
+                auditLogger.LogInformation(
+                    BrokerEventIds.AuthenticationInvalidRequest,
+                    "Authentication request had an invalid institutional user format after {ElapsedMilliseconds} ms.",
+                    elapsed.ElapsedMilliseconds);
+                break;
+        }
+
        return result.Outcome switch
        {
            AuthenticationFlowOutcome.Authorized => Results.Ok(new AuthenticationResponse(
@@ -125,3 +185,11 @@ static IResult Unavailable(HttpContext context, string? errorCode)

 static string NormalizeThumbprint(string value) =>
    value.Replace(" ", string.Empty, StringComparison.Ordinal).ToUpperInvariant();
+
+static string SafeUserName(string? value)
+{
+    string candidate = value?.Trim().ToUpperInvariant() ?? string.Empty;
+    return candidate.Length is > 0 and <= 16 && candidate.All(char.IsAsciiLetterOrDigit)
+        ? candidate
+        : "<invalid-format>";
+}
@@ -7,7 +7,9 @@ using SGU.AuthBroker.Options;

 namespace SGU.AuthBroker.Services;

-public sealed class ActiveDirectorySynchronizer(BrokerOptions options) : IActiveDirectorySynchronizer
+public sealed class ActiveDirectorySynchronizer(
+    BrokerOptions options,
+    ILogger<ActiveDirectorySynchronizer> logger) : IActiveDirectorySynchronizer
 {
    private const int AccountDisabled = 0x0002;
    private const int NormalAccount = 0x0200;
@@ -28,9 +30,26 @@ public sealed class ActiveDirectorySynchronizer(BrokerOptions options) : IActive
        await gate.WaitAsync(cancellationToken).ConfigureAwait(false);
        try
        {
-            return await Task.Run(
-                () => Synchronize(identity, profile, password),
-                cancellationToken).ConfigureAwait(false);
+            try
+            {
+                return await Task.Run(
+                    () => Synchronize(identity, profile, password),
+                    cancellationToken).ConfigureAwait(false);
+            }
+            catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested)
+            {
+                throw;
+            }
+            catch (Exception exception)
+            {
+                logger.LogError(
+                    BrokerEventIds.DirectorySynchronizationFailure,
+                    exception,
+                    "Active Directory synchronization failed for {InstitutionalUser} with role {Role}.",
+                    identity.UserName,
+                    identity.Role);
+                throw;
+            }
        }
        finally
        {
@@ -100,8 +119,8 @@ public sealed class ActiveDirectorySynchronizer(BrokerOptions options) : IActive
            user.Properties["pwdLastSet"].Value = -1;
            user.CommitChanges();

-            TryApplyProfile(user, identity, profile, options.DefaultCompany);
-            TryEnsureRemoteDesktopGroupMembership(user);
+            TryApplyProfile(user, identity, profile, options.DefaultCompany, logger);
+            TryEnsureRemoteDesktopGroupMembership(user, identity.UserName);

            return new DirectorySyncResult(
                options.DomainNetbios,
@@ -120,7 +139,8 @@ public sealed class ActiveDirectorySynchronizer(BrokerOptions options) : IActive
        DirectoryEntry user,
        UserIdentity identity,
        InstitutionalProfile? profile,
-        string defaultCompany)
+        string defaultCompany,
+        ILogger logger)
    {
        try
        {
@@ -146,10 +166,15 @@ public sealed class ActiveDirectorySynchronizer(BrokerOptions options) : IActive

            user.CommitChanges();
        }
-        catch
+        catch (Exception exception)
        {
            // Metadata is intentionally best-effort. User creation, password sync,
            // and account enablement have already committed successfully.
+            logger.LogWarning(
+                BrokerEventIds.DirectoryOptionalMetadataFailure,
+                exception,
+                "Optional Active Directory profile metadata could not be committed for {InstitutionalUser}; password synchronization remains completed.",
+                identity.UserName);
            try
            {
                user.RefreshCache();
@@ -170,7 +195,7 @@ public sealed class ActiveDirectorySynchronizer(BrokerOptions options) : IActive
        }
    }

-    private void TryEnsureRemoteDesktopGroupMembership(DirectoryEntry user)
+    private void TryEnsureRemoteDesktopGroupMembership(DirectoryEntry user, string institutionalUser)
    {
        if (string.IsNullOrWhiteSpace(options.RemoteDesktopGroupDn))
        {
@@ -194,10 +219,15 @@ public sealed class ActiveDirectorySynchronizer(BrokerOptions options) : IActive
                group.CommitChanges();
            }
        }
-        catch
+        catch (Exception exception)
        {
            // Remote access is lab policy and must not invalidate a completed
            // password synchronization if the optional group is unavailable.
+            logger.LogWarning(
+                BrokerEventIds.DirectoryGroupMembershipFailure,
+                exception,
+                "Optional remote-desktop group membership could not be updated for {InstitutionalUser}; password synchronization remains completed.",
+                institutionalUser);
        }
    }

@@ -35,6 +35,10 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
        string password,
        CancellationToken cancellationToken)
    {
+        using IDisposable? logScope = logger.BeginScope(
+            "InstitutionalUser={InstitutionalUser}; InstitutionalRole={InstitutionalRole}",
+            identity.UserName,
+            identity.Role);
        Uri authenticationUri = new(
            new Uri(options.Endpoint, UriKind.Absolute),
            options.AuthenticationPath);
@@ -155,6 +159,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
                    }

                    logger.LogInformation(
+                        BrokerEventIds.SguAuthenticationAccepted,
                        "SGU accepted credentials after an explicit NTLM challenge in {ElapsedMilliseconds} ms.",
                        elapsed.ElapsedMilliseconds);
                    return (null, continuationUri);
@@ -184,6 +189,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
        catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested)
        {
            logger.LogWarning(
+                BrokerEventIds.SguAuthenticationTimeout,
                "SGU NTLM authentication timed out after {ElapsedMilliseconds} ms.",
                elapsed.ElapsedMilliseconds);
            return (NtlmValidationResult.Unavailable("NTLM_TIMEOUT"), null);
@@ -191,6 +197,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
        catch (HttpRequestException exception)
        {
            logger.LogWarning(
+                BrokerEventIds.SguAuthenticationNetworkFailure,
                exception,
                "SGU NTLM authentication failed after {ElapsedMilliseconds} ms.",
                elapsed.ElapsedMilliseconds);
@@ -347,6 +354,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
                    if (profile is null)
                    {
                        logger.LogWarning(
+                            BrokerEventIds.ProfileHtmlUnexpected,
                            "SGU returned a profile page for role {Role}, but no supported profile fields were found after {ElapsedMilliseconds} ms.",
                            identity.Role,
                            elapsed.ElapsedMilliseconds);
@@ -354,8 +362,10 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
                    else
                    {
                        logger.LogInformation(
-                            "SGU profile enrichment completed for role {Role} in {ElapsedMilliseconds} ms.",
+                            BrokerEventIds.ProfileEnrichmentCompleted,
+                            "SGU profile enrichment completed for role {Role} with {ProfileFieldCount} supported fields in {ElapsedMilliseconds} ms.",
                            identity.Role,
+                            CountProfileFields(profile),
                            elapsed.ElapsedMilliseconds);
                    }

@@ -382,6 +392,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
        catch (OperationCanceledException)
        {
            logger.LogWarning(
+                BrokerEventIds.ProfileEnrichmentTimeout,
                "SGU profile request for role {Role} timed out after {ElapsedMilliseconds} ms.",
                identity.Role,
                elapsed.ElapsedMilliseconds);
@@ -389,6 +400,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
        catch (Exception exception)
        {
            logger.LogWarning(
+                BrokerEventIds.ProfileEnrichmentFailure,
                exception,
                "SGU profile enrichment failed for role {Role} after {ElapsedMilliseconds} ms.",
                identity.Role,
@@ -423,11 +435,33 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
                    GetProfileUri(path),
                    allowedHosts,
                    timeoutToken).ConfigureAwait(false);
-                profile = profile.Overlay(html is null ? null : parser(html));
+                if (html is null)
+                {
+                    logger.LogWarning(
+                        BrokerEventIds.ProfilePageUnavailable,
+                        "Optional SGU profile page {Path} did not return usable HTML for role {Role}; preserving fields already collected.",
+                        path,
+                        role);
+                    continue;
+                }
+
+                InstitutionalProfile? pageProfile = parser(html);
+                if (pageProfile is null)
+                {
+                    logger.LogWarning(
+                        BrokerEventIds.ProfileHtmlUnexpected,
+                        "Optional SGU profile page {Path} returned HTML without its supported field IDs for role {Role}; preserving fields already collected.",
+                        path,
+                        role);
+                    continue;
+                }
+
+                profile = profile.Overlay(pageProfile);
            }
            catch (OperationCanceledException) when (!requestCancellationToken.IsCancellationRequested)
            {
                logger.LogWarning(
+                    BrokerEventIds.ProfileEnrichmentTimeout,
                    "SGU optional staff profile enrichment for role {Role} reached its total timeout after {ElapsedMilliseconds} ms; preserving fields already collected.",
                    role,
                    elapsed.ElapsedMilliseconds);
@@ -436,6 +470,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
            catch (Exception exception)
            {
                logger.LogWarning(
+                    BrokerEventIds.ProfileEnrichmentFailure,
                    exception,
                    "An optional SGU staff profile page for role {Role} failed after {ElapsedMilliseconds} ms; preserving fields already collected.",
                    role,
@@ -487,6 +522,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
            }

            logger.LogWarning(
+                BrokerEventIds.ProfilePageUnavailable,
                "Optional SGU profile page {Path} returned HTTP {StatusCode}.",
                requestedUri.AbsolutePath,
                statusCode);
@@ -494,6 +530,7 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
        }

        logger.LogWarning(
+            BrokerEventIds.ProfilePageUnavailable,
            "Optional SGU profile page {Path} exceeded the redirect limit.",
            requestedUri.AbsolutePath);
        return null;
@@ -550,6 +587,23 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
            right.AbsolutePath.TrimEnd('/'),
            StringComparison.OrdinalIgnoreCase);

+    private static int CountProfileFields(InstitutionalProfile profile) =>
+        new[]
+        {
+            profile.EmployeeNumber,
+            profile.DisplayName,
+            profile.GivenName,
+            profile.Surname,
+            profile.Email,
+            profile.EmployeeType,
+            profile.JobTitle,
+            profile.Department,
+            profile.StreetAddress,
+            profile.City,
+            profile.State,
+            profile.PostalCode
+        }.Count(value => !string.IsNullOrWhiteSpace(value));
+
    private static async Task DrainResponseAsync(
        HttpResponseMessage response,
        CancellationToken cancellationToken)
@@ -604,17 +658,31 @@ public sealed class NtlmCredentialValidator : INtlmCredentialValidator
            response.Content,
            options.MaxProfileBytes,
            timeoutToken).ConfigureAwait(false);
-        return identity.Role switch
+        InstitutionalProfile? profile;
+        switch (identity.Role)
        {
-            InstitutionalRole.Administrative =>
-                SguProfileParser.ParseAdministrative(html, identity.NumericId) ??
-                SguProfileParser.ParseMenu(html),
-            InstitutionalRole.Student =>
-                SguProfileParser.ParseStudent(html, identity.NumericId) ??
-                SguProfileParser.ParseMenu(html),
-            InstitutionalRole.Professor => SguProfileParser.ParseMenu(html),
-            _ => null
-        };
+            case InstitutionalRole.Administrative:
+                profile = SguProfileParser.ParseAdministrative(html, identity.NumericId);
+                break;
+            case InstitutionalRole.Student:
+                profile = SguProfileParser.ParseStudent(html, identity.NumericId);
+                break;
+            case InstitutionalRole.Professor:
+                return SguProfileParser.ParseMenu(html);
+            default:
+                return null;
+        }
+
+        if (profile is not null)
+        {
+            return profile;
+        }
+
+        logger.LogWarning(
+            BrokerEventIds.ProfileHtmlUnexpected,
+            "The primary SGU profile HTML did not contain the supported field IDs for role {Role}; attempting the menu-name fallback.",
+            identity.Role);
+        return SguProfileParser.ParseMenu(html);
    }

    private static async Task<string> ReadLimitedStringAsync(