[PM-22405] Add debugging instrument for finding invalid OrganizationUser state. (#5955)

src/Core/AdminConsole/Services/Implementations/OrganizationService.cs

@@ -11,6 +11,7 @@ using Bit.Core.AdminConsole.OrganizationFeatures.Policies;
 using Bit.Core.AdminConsole.OrganizationFeatures.Policies.PolicyRequirements;
 using Bit.Core.AdminConsole.Repositories;
 using Bit.Core.AdminConsole.Services;
+using Bit.Core.AdminConsole.Utilities.DebuggingInstruments;
 using Bit.Core.Auth.Enums;
 using Bit.Core.Auth.Repositories;
 using Bit.Core.Billing.Constants;
@@ -900,6 +901,8 @@ public class OrganizationService : IOrganizationService
         IEnumerable<Guid> organizationUsersId)
     {
         var orgUsers = await _organizationUserRepository.GetManyAsync(organizationUsersId);
+        _logger.LogUserInviteStateDiagnostics(orgUsers);
+
         var org = await GetOrgById(organizationId);
 
         var result = new List<Tuple<OrganizationUser, string>>();
@@ -928,6 +931,8 @@ public class OrganizationService : IOrganizationService
             throw new BadRequestException("User invalid.");
         }
 
+        _logger.LogUserInviteStateDiagnostics(orgUser);
+
         var org = await GetOrgById(orgUser.OrganizationId);
         await SendInviteAsync(orgUser, org, initOrganization);
     }

src/Core/AdminConsole/Utilities/DebuggingInstruments/UserInviteDebuggingLogger.cs

@@ -0,0 +1,67 @@
+using System.Text.Json;
+using Bit.Core.Entities;
+using Bit.Core.Enums;
+using Microsoft.Extensions.Logging;
+using Quartz.Util;
+
+namespace Bit.Core.AdminConsole.Utilities.DebuggingInstruments;
+
+/// <summary>
+/// Temporary code: Log warning when OrganizationUser is in an invalid state,
+/// so we can identify which flow is causing the issue through Datadog.
+/// </summary>
+public static class UserInviteDebuggingLogger
+{
+    public static void LogUserInviteStateDiagnostics(this ILogger logger, OrganizationUser orgUser)
+    {
+        LogUserInviteStateDiagnostics(logger, [orgUser]);
+    }
+
+    public static void LogUserInviteStateDiagnostics(this ILogger logger, IEnumerable<OrganizationUser> allOrgUsers)
+    {
+        try
+        {
+            var invalidInviteState = allOrgUsers.Any(user => user.Status == OrganizationUserStatusType.Invited && user.Email.IsNullOrWhiteSpace());
+
+            if (invalidInviteState)
+            {
+                var logData = MapObjectDataToLog(allOrgUsers);
+                logger.LogWarning("Warning invalid invited state. {logData}", logData);
+            }
+
+            var invalidConfirmedOrAcceptedState = allOrgUsers.Any(user => (user.Status == OrganizationUserStatusType.Confirmed || user.Status == OrganizationUserStatusType.Accepted) && !user.Email.IsNullOrWhiteSpace());
+
+            if (invalidConfirmedOrAcceptedState)
+            {
+                var logData = MapObjectDataToLog(allOrgUsers);
+                logger.LogWarning("Warning invalid confirmed or accepted state. {logData}", logData);
+            }
+        }
+        catch (Exception exception)
+        {
+
+            // Ensure that this debugging instrument does not interfere with the current flow.
+            logger.LogWarning(exception, "Unexpected exception from UserInviteDebuggingLogger");
+        }
+    }
+
+    private static string MapObjectDataToLog(IEnumerable<OrganizationUser> allOrgUsers)
+    {
+        var log = allOrgUsers.Select(allOrgUser => new
+        {
+            allOrgUser.OrganizationId,
+            allOrgUser.Status,
+            hasEmail = !allOrgUser.Email.IsNullOrWhiteSpace(),
+            userId = allOrgUser.UserId,
+            allOrgUserId = allOrgUser.Id
+        });
+
+        var options = new JsonSerializerOptions
+        {
+            PropertyNamingPolicy = JsonNamingPolicy.CamelCase,
+            WriteIndented = true
+        };
+
+        return JsonSerializer.Serialize(log, options);
+    }
+}

src/Infrastructure.Dapper/AdminConsole/Repositories/OrganizationUserRepository.cs

@@ -3,6 +3,7 @@ using System.Text.Json;
 using Bit.Core.AdminConsole.Entities;
 using Bit.Core.AdminConsole.Enums;
 using Bit.Core.AdminConsole.OrganizationFeatures.OrganizationUsers.InviteUsers.Models;
+using Bit.Core.AdminConsole.Utilities.DebuggingInstruments;
 using Bit.Core.Entities;
 using Bit.Core.Enums;
 using Bit.Core.KeyManagement.UserKey;
@@ -12,6 +13,7 @@ using Bit.Core.Repositories;
 using Bit.Core.Settings;
 using Dapper;
 using Microsoft.Data.SqlClient;
+using Microsoft.Extensions.Logging;
 
 #nullable enable
 
@@ -25,8 +27,9 @@ public class OrganizationUserRepository : Repository<OrganizationUser, Guid>, IO
     /// https://github.com/dotnet/SqlClient/issues/54
     /// </summary>
     private string _marsConnectionString;
+    private readonly ILogger<OrganizationUserRepository> _logger;
 
-    public OrganizationUserRepository(GlobalSettings globalSettings)
+    public OrganizationUserRepository(GlobalSettings globalSettings, ILogger<OrganizationUserRepository> logger)
         : base(globalSettings.SqlServer.ConnectionString, globalSettings.SqlServer.ReadOnlyConnectionString)
     {
         var builder = new SqlConnectionStringBuilder(ConnectionString)
@@ -34,6 +37,7 @@ public class OrganizationUserRepository : Repository<OrganizationUser, Guid>, IO
             MultipleActiveResultSets = true,
         };
         _marsConnectionString = builder.ToString();
+        _logger = logger;
     }
 
     public async Task<int> GetCountByOrganizationIdAsync(Guid organizationId)
@@ -305,6 +309,8 @@ public class OrganizationUserRepository : Repository<OrganizationUser, Guid>, IO
 
     public async Task<Guid> CreateAsync(OrganizationUser obj, IEnumerable<CollectionAccessSelection> collections)
     {
+        _logger.LogUserInviteStateDiagnostics(obj);
+
         obj.SetNewId();
         var objWithCollections = JsonSerializer.Deserialize<OrganizationUserWithCollections>(
             JsonSerializer.Serialize(obj))!;
@@ -323,6 +329,8 @@ public class OrganizationUserRepository : Repository<OrganizationUser, Guid>, IO
 
     public async Task ReplaceAsync(OrganizationUser obj, IEnumerable<CollectionAccessSelection> collections)
     {
+        _logger.LogUserInviteStateDiagnostics(obj);
+
         var objWithCollections = JsonSerializer.Deserialize<OrganizationUserWithCollections>(
             JsonSerializer.Serialize(obj))!;
         objWithCollections.Collections = collections.ToArrayTVP();
@@ -406,6 +414,8 @@ public class OrganizationUserRepository : Repository<OrganizationUser, Guid>, IO
 
     public async Task<ICollection<Guid>?> CreateManyAsync(IEnumerable<OrganizationUser> organizationUsers)
     {
+        _logger.LogUserInviteStateDiagnostics(organizationUsers);
+
         organizationUsers = organizationUsers.ToList();
         if (!organizationUsers.Any())
         {
@@ -430,6 +440,8 @@ public class OrganizationUserRepository : Repository<OrganizationUser, Guid>, IO
 
     public async Task ReplaceManyAsync(IEnumerable<OrganizationUser> organizationUsers)
     {
+        _logger.LogUserInviteStateDiagnostics(organizationUsers);
+
         organizationUsers = organizationUsers.ToList();
         if (!organizationUsers.Any())
         {

test/Core.Test/AdminConsole/Utilities/DebuggingInstruments/UserInviteDebuggingLoggerTests.cs

@@ -0,0 +1,113 @@
+using Bit.Core.AdminConsole.Utilities.DebuggingInstruments;
+using Bit.Core.Entities;
+using Bit.Core.Enums;
+using Microsoft.Extensions.Logging;
+using NSubstitute;
+using Xunit;
+
+namespace Bit.Core.Test.AdminConsole.Utilities.DebuggingInstruments;
+
+public class UserInviteDebuggingLoggerTests
+{
+    [Fact]
+    public void LogUserInviteStateDiagnostics_WhenInvitedUserHasNoEmail_LogsWarning()
+    {
+        // Arrange
+        var organizationUser = new OrganizationUser
+        {
+            OrganizationId = Guid.Parse("3e1f2196-9ad6-4ba7-b69d-ba33bc25f774"),
+            Status = OrganizationUserStatusType.Invited,
+            Email = string.Empty,
+            UserId = Guid.Parse("93fbddd1-e96d-491d-a38b-6966ff59ac28"),
+            Id = Guid.Parse("326f043f-afdc-47e5-9646-a76ab709b69a"),
+        };
+
+        var logger = Substitute.For<ILogger>();
+
+        // Act
+        logger.LogUserInviteStateDiagnostics(organizationUser);
+
+        // Assert
+        logger.Received(1).Log(
+            LogLevel.Warning,
+            Arg.Any<EventId>(),
+            Arg.Is<object>(errorMessage =>
+                errorMessage.ToString().Contains("Warning invalid invited state")
+                && errorMessage.ToString().Contains(organizationUser.OrganizationId.ToString())
+                && errorMessage.ToString().Contains(organizationUser.UserId.ToString())
+                && errorMessage.ToString().Contains(organizationUser.Id.ToString())
+            ),
+            null,
+            Arg.Any<Func<object, Exception, string>>()
+        );
+    }
+
+    public static IEnumerable<object[]> ConfirmedOrAcceptedTestCases =>
+    [
+       new object[] { OrganizationUserStatusType.Accepted },
+        new object[] { OrganizationUserStatusType.Confirmed },
+    ];
+
+    [Theory]
+    [MemberData(nameof(ConfirmedOrAcceptedTestCases))]
+    public void LogUserInviteStateDiagnostics_WhenNonInvitedUserHasEmail_LogsWarning(OrganizationUserStatusType userStatusType)
+    {
+        // Arrange
+        var organizationUser = new OrganizationUser
+        {
+            OrganizationId = Guid.Parse("3e1f2196-9ad6-4ba7-b69d-ba33bc25f774"),
+            Status = userStatusType,
+            Email = "someone@example.com",
+            UserId = Guid.Parse("93fbddd1-e96d-491d-a38b-6966ff59ac28"),
+            Id = Guid.Parse("326f043f-afdc-47e5-9646-a76ab709b69a"),
+        };
+
+        var logger = Substitute.For<ILogger>();
+
+        // Act
+        logger.LogUserInviteStateDiagnostics(organizationUser);
+
+        // Assert
+        logger.Received(1).Log(
+            LogLevel.Warning,
+            Arg.Any<EventId>(),
+            Arg.Is<object>(errorMessage =>
+                errorMessage.ToString().Contains("Warning invalid confirmed or accepted state")
+                && errorMessage.ToString().Contains(organizationUser.OrganizationId.ToString())
+                && errorMessage.ToString().Contains(organizationUser.UserId.ToString())
+                && errorMessage.ToString().Contains(organizationUser.Id.ToString())
+                // Ensure that no PII is included in the log.
+                && !errorMessage.ToString().Contains(organizationUser.Email)
+            ),
+            null,
+            Arg.Any<Func<object, Exception, string>>()
+        );
+    }
+
+
+    public static List<object[]> ShouldNotLogTestCases =>
+    [
+        new object[] { new OrganizationUser { Status = OrganizationUserStatusType.Accepted, Email = null } },
+        new object[] { new OrganizationUser { Status = OrganizationUserStatusType.Confirmed, Email = null } },
+        new object[] { new OrganizationUser { Status = OrganizationUserStatusType.Invited, Email = "someone@example.com" } },
+        new object[] { new OrganizationUser { Status = OrganizationUserStatusType.Revoked, Email = null } },
+    ];
+
+    [Theory]
+    [MemberData(nameof(ShouldNotLogTestCases))]
+    public void LogUserInviteStateDiagnostics_WhenStateAreValid_ShouldNotLog(OrganizationUser user)
+    {
+        var logger = Substitute.For<ILogger>();
+
+        // Act
+        logger.LogUserInviteStateDiagnostics(user);
+
+        // Assert
+        logger.DidNotReceive().Log(
+            Arg.Any<LogLevel>(),
+            Arg.Any<EventId>(),
+            Arg.Any<object>(),
+            Arg.Any<Exception>(),
+            Arg.Any<Func<object, Exception, string>>());
+    }
+}