1
0
mirror of https://github.com/bitwarden/server synced 2025-12-10 21:33:41 +00:00

[PM-17562] Update logs to use custom categories (#6145)

* [PM-17562] Update logs to use custom categories

* Added tests to verify hardcoded names match the real type
This commit is contained in:
Brant DeBow
2025-08-01 08:46:00 -04:00
committed by GitHub
parent 6f4a0c4a61
commit ccedefb8b8
10 changed files with 192 additions and 60 deletions

View File

@@ -1,4 +1,6 @@
using System.Text.Json;
#nullable enable
using System.Text.Json;
using Azure.Messaging.ServiceBus;
using Bit.Core.AdminConsole.Models.Data.EventIntegrations;
using Bit.Core.Models.Data;
@@ -17,14 +19,31 @@ public class AzureServiceBusEventListenerServiceTests
{
private const string _messageId = "messageId";
private readonly TestListenerConfiguration _config = new();
private readonly ILogger _logger = Substitute.For<ILogger>();
private SutProvider<AzureServiceBusEventListenerService<TestListenerConfiguration>> GetSutProvider()
{
var loggerFactory = Substitute.For<ILoggerFactory>();
loggerFactory.CreateLogger<object>().ReturnsForAnyArgs(_logger);
return new SutProvider<AzureServiceBusEventListenerService<TestListenerConfiguration>>()
.SetDependency(_config)
.SetDependency(loggerFactory)
.Create();
}
[Fact]
public void Constructor_CreatesLogWithCorrectCategory()
{
var sutProvider = GetSutProvider();
var fullName = typeof(AzureServiceBusEventListenerService<>).FullName ?? "";
var tickIndex = fullName.IndexOf('`');
var cleanedName = tickIndex >= 0 ? fullName.Substring(0, tickIndex) : fullName;
var categoryName = cleanedName + '.' + _config.EventSubscriptionName;
sutProvider.GetDependency<ILoggerFactory>().Received(1).CreateLogger(categoryName);
}
[Fact]
public void Constructor_CreatesProcessor()
{
@@ -44,12 +63,12 @@ public class AzureServiceBusEventListenerServiceTests
await sutProvider.Sut.ProcessErrorAsync(args);
sutProvider.GetDependency<ILogger<AzureServiceBusEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<Exception>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Fact]
@@ -58,26 +77,26 @@ public class AzureServiceBusEventListenerServiceTests
var sutProvider = GetSutProvider();
await sutProvider.Sut.ProcessReceivedMessageAsync(string.Empty, _messageId);
sutProvider.GetDependency<ILogger<AzureServiceBusEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<JsonException>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Fact]
public async Task ProcessReceivedMessageAsync_InvalidJson_LogsError()
{
var sutProvider = GetSutProvider();
await sutProvider.Sut.ProcessReceivedMessageAsync("{ Inavlid JSON }", _messageId);
await sutProvider.Sut.ProcessReceivedMessageAsync("{ Invalid JSON }", _messageId);
sutProvider.GetDependency<ILogger<AzureServiceBusEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Is<object>(o => o.ToString().Contains("Invalid JSON")),
Arg.Is<object>(o => (o.ToString() ?? "").Contains("Invalid JSON")),
Arg.Any<Exception>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Fact]
@@ -89,12 +108,12 @@ public class AzureServiceBusEventListenerServiceTests
_messageId
);
sutProvider.GetDependency<ILogger<AzureServiceBusEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<JsonException>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Fact]
@@ -106,12 +125,12 @@ public class AzureServiceBusEventListenerServiceTests
_messageId
);
sutProvider.GetDependency<ILogger<AzureServiceBusEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<JsonException>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Theory, BitAutoData]

View File

@@ -1,5 +1,6 @@
#nullable enable
using System.Text.Json;
using Azure.Messaging.ServiceBus;
using Bit.Core.AdminConsole.Models.Data.EventIntegrations;
using Bit.Core.Services;
@@ -7,6 +8,7 @@ using Bit.Test.Common.AutoFixture;
using Bit.Test.Common.AutoFixture.Attributes;
using Microsoft.Extensions.Logging;
using NSubstitute;
using NSubstitute.ExceptionExtensions;
using Xunit;
namespace Bit.Core.Test.Services;
@@ -15,18 +17,35 @@ namespace Bit.Core.Test.Services;
public class AzureServiceBusIntegrationListenerServiceTests
{
private readonly IIntegrationHandler _handler = Substitute.For<IIntegrationHandler>();
private readonly ILogger _logger = Substitute.For<ILogger>();
private readonly IAzureServiceBusService _serviceBusService = Substitute.For<IAzureServiceBusService>();
private readonly TestListenerConfiguration _config = new();
private SutProvider<AzureServiceBusIntegrationListenerService<TestListenerConfiguration>> GetSutProvider()
{
var loggerFactory = Substitute.For<ILoggerFactory>();
loggerFactory.CreateLogger<object>().ReturnsForAnyArgs(_logger);
return new SutProvider<AzureServiceBusIntegrationListenerService<TestListenerConfiguration>>()
.SetDependency(_config)
.SetDependency(loggerFactory)
.SetDependency(_handler)
.SetDependency(_serviceBusService)
.Create();
}
[Fact]
public void Constructor_CreatesLogWithCorrectCategory()
{
var sutProvider = GetSutProvider();
var fullName = typeof(AzureServiceBusIntegrationListenerService<>).FullName ?? "";
var tickIndex = fullName.IndexOf('`');
var cleanedName = tickIndex >= 0 ? fullName.Substring(0, tickIndex) : fullName;
var categoryName = cleanedName + '.' + _config.IntegrationSubscriptionName;
sutProvider.GetDependency<ILoggerFactory>().Received(1).CreateLogger(categoryName);
}
[Fact]
public void Constructor_CreatesProcessor()
{
@@ -45,7 +64,7 @@ public class AzureServiceBusIntegrationListenerServiceTests
var sutProvider = GetSutProvider();
await sutProvider.Sut.ProcessErrorAsync(args);
sutProvider.GetDependency<ILogger<AzureServiceBusIntegrationListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
@@ -63,12 +82,13 @@ public class AzureServiceBusIntegrationListenerServiceTests
result.Retryable = false;
_handler.HandleAsync(Arg.Any<string>()).Returns(result);
var expected = (IntegrationMessage<WebhookIntegrationConfiguration>)IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson())!;
var expected = IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson());
Assert.NotNull(expected);
Assert.False(await sutProvider.Sut.HandleMessageAsync(message.ToJson()));
await _handler.Received(1).HandleAsync(Arg.Is(expected.ToJson()));
await _serviceBusService.DidNotReceiveWithAnyArgs().PublishToRetryAsync(default!);
await _serviceBusService.DidNotReceiveWithAnyArgs().PublishToRetryAsync(Arg.Any<IIntegrationMessage>());
}
[Theory, BitAutoData]
@@ -81,12 +101,13 @@ public class AzureServiceBusIntegrationListenerServiceTests
_handler.HandleAsync(Arg.Any<string>()).Returns(result);
var expected = (IntegrationMessage<WebhookIntegrationConfiguration>)IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson())!;
var expected = IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson());
Assert.NotNull(expected);
Assert.False(await sutProvider.Sut.HandleMessageAsync(message.ToJson()));
await _handler.Received(1).HandleAsync(Arg.Is(expected.ToJson()));
await _serviceBusService.DidNotReceiveWithAnyArgs().PublishToRetryAsync(default!);
await _serviceBusService.DidNotReceiveWithAnyArgs().PublishToRetryAsync(Arg.Any<IIntegrationMessage>());
}
[Theory, BitAutoData]
@@ -99,7 +120,8 @@ public class AzureServiceBusIntegrationListenerServiceTests
result.Retryable = true;
_handler.HandleAsync(Arg.Any<string>()).Returns(result);
var expected = (IntegrationMessage<WebhookIntegrationConfiguration>)IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson())!;
var expected = IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson());
Assert.NotNull(expected);
Assert.True(await sutProvider.Sut.HandleMessageAsync(message.ToJson()));
@@ -114,11 +136,30 @@ public class AzureServiceBusIntegrationListenerServiceTests
var result = new IntegrationHandlerResult(true, message);
_handler.HandleAsync(Arg.Any<string>()).Returns(result);
var expected = (IntegrationMessage<WebhookIntegrationConfiguration>)IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson())!;
var expected = IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson());
Assert.NotNull(expected);
Assert.True(await sutProvider.Sut.HandleMessageAsync(message.ToJson()));
await _handler.Received(1).HandleAsync(Arg.Is(expected.ToJson()));
await _serviceBusService.DidNotReceiveWithAnyArgs().PublishToRetryAsync(default!);
await _serviceBusService.DidNotReceiveWithAnyArgs().PublishToRetryAsync(Arg.Any<IIntegrationMessage>());
}
[Fact]
public async Task HandleMessageAsync_UnknownError_LogsError()
{
var sutProvider = GetSutProvider();
_handler.HandleAsync(Arg.Any<string>()).ThrowsAsync<JsonException>();
Assert.True(await sutProvider.Sut.HandleMessageAsync("Bad JSON"));
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<Exception>(),
Arg.Any<Func<object, Exception?, string>>());
await _serviceBusService.DidNotReceiveWithAnyArgs().PublishToRetryAsync(Arg.Any<IIntegrationMessage>());
}
}

View File

@@ -1,4 +1,6 @@
using System.Text.Json;
#nullable enable
using System.Text.Json;
using Bit.Core.AdminConsole.Models.Data.EventIntegrations;
using Bit.Core.Models.Data;
using Bit.Core.Services;
@@ -17,14 +19,31 @@ namespace Bit.Core.Test.Services;
public class RabbitMqEventListenerServiceTests
{
private readonly TestListenerConfiguration _config = new();
private readonly ILogger _logger = Substitute.For<ILogger>();
private SutProvider<RabbitMqEventListenerService<TestListenerConfiguration>> GetSutProvider()
{
var loggerFactory = Substitute.For<ILoggerFactory>();
loggerFactory.CreateLogger<object>().ReturnsForAnyArgs(_logger);
return new SutProvider<RabbitMqEventListenerService<TestListenerConfiguration>>()
.SetDependency(_config)
.SetDependency(loggerFactory)
.Create();
}
[Fact]
public void Constructor_CreatesLogWithCorrectCategory()
{
var sutProvider = GetSutProvider();
var fullName = typeof(RabbitMqEventListenerService<>).FullName ?? "";
var tickIndex = fullName.IndexOf('`');
var cleanedName = tickIndex >= 0 ? fullName.Substring(0, tickIndex) : fullName;
var categoryName = cleanedName + '.' + _config.EventQueueName;
sutProvider.GetDependency<ILoggerFactory>().Received(1).CreateLogger(categoryName);
}
[Fact]
public async Task StartAsync_CreatesQueue()
{
@@ -53,12 +72,12 @@ public class RabbitMqEventListenerServiceTests
await sutProvider.Sut.ProcessReceivedMessageAsync(eventArgs);
sutProvider.GetDependency<ILogger<RabbitMqEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<JsonException>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Fact]
@@ -76,12 +95,12 @@ public class RabbitMqEventListenerServiceTests
await sutProvider.Sut.ProcessReceivedMessageAsync(eventArgs);
sutProvider.GetDependency<ILogger<RabbitMqEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Is<object>(o => o.ToString().Contains("Invalid JSON")),
Arg.Is<object>(o => (o.ToString() ?? "").Contains("Invalid JSON")),
Arg.Any<Exception>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Fact]
@@ -99,12 +118,12 @@ public class RabbitMqEventListenerServiceTests
await sutProvider.Sut.ProcessReceivedMessageAsync(eventArgs);
sutProvider.GetDependency<ILogger<RabbitMqEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<JsonException>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Fact]
@@ -122,12 +141,12 @@ public class RabbitMqEventListenerServiceTests
await sutProvider.Sut.ProcessReceivedMessageAsync(eventArgs);
sutProvider.GetDependency<ILogger<RabbitMqEventListenerService<TestListenerConfiguration>>>().Received(1).Log(
_logger.Received(1).Log(
LogLevel.Error,
Arg.Any<EventId>(),
Arg.Any<object>(),
Arg.Any<JsonException>(),
Arg.Any<Func<object, Exception, string>>());
Arg.Any<Func<object, Exception?, string>>());
}
[Theory, BitAutoData]

View File

@@ -1,9 +1,12 @@
using System.Text;
#nullable enable
using System.Text;
using Bit.Core.AdminConsole.Models.Data.EventIntegrations;
using Bit.Core.Services;
using Bit.Test.Common.AutoFixture;
using Bit.Test.Common.AutoFixture.Attributes;
using Bit.Test.Common.Helpers;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Time.Testing;
using NSubstitute;
using RabbitMQ.Client;
@@ -17,14 +20,18 @@ public class RabbitMqIntegrationListenerServiceTests
{
private readonly DateTime _now = new DateTime(2014, 3, 2, 1, 0, 0, DateTimeKind.Utc);
private readonly IIntegrationHandler _handler = Substitute.For<IIntegrationHandler>();
private readonly ILogger _logger = Substitute.For<ILogger>();
private readonly IRabbitMqService _rabbitMqService = Substitute.For<IRabbitMqService>();
private readonly TestListenerConfiguration _config = new();
private SutProvider<RabbitMqIntegrationListenerService<TestListenerConfiguration>> GetSutProvider()
{
var loggerFactory = Substitute.For<ILoggerFactory>();
loggerFactory.CreateLogger<object>().ReturnsForAnyArgs(_logger);
var sutProvider = new SutProvider<RabbitMqIntegrationListenerService<TestListenerConfiguration>>()
.SetDependency(_config)
.SetDependency(_handler)
.SetDependency(loggerFactory)
.SetDependency(_rabbitMqService)
.WithFakeTimeProvider()
.Create();
@@ -33,6 +40,19 @@ public class RabbitMqIntegrationListenerServiceTests
return sutProvider;
}
[Fact]
public void Constructor_CreatesLogWithCorrectCategory()
{
var sutProvider = GetSutProvider();
var fullName = typeof(RabbitMqIntegrationListenerService<>).FullName ?? "";
var tickIndex = fullName.IndexOf('`');
var cleanedName = tickIndex >= 0 ? fullName.Substring(0, tickIndex) : fullName;
var categoryName = cleanedName + '.' + _config.IntegrationQueueName;
sutProvider.GetDependency<ILoggerFactory>().Received(1).CreateLogger(categoryName);
}
[Fact]
public async Task StartAsync_CreatesQueues()
{
@@ -71,6 +91,7 @@ public class RabbitMqIntegrationListenerServiceTests
_handler.HandleAsync(Arg.Any<string>()).Returns(result);
var expected = IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson());
Assert.NotNull(expected);
await sutProvider.Sut.ProcessReceivedMessageAsync(eventArgs, cancellationToken);
@@ -81,10 +102,17 @@ public class RabbitMqIntegrationListenerServiceTests
Arg.Is(AssertHelper.AssertPropertyEqual(expected, new[] { "DelayUntilDate" })),
Arg.Any<CancellationToken>());
_logger.Received().Log(
LogLevel.Warning,
Arg.Any<EventId>(),
Arg.Is<object>(o => (o.ToString() ?? "").Contains("Non-retryable failure")),
Arg.Any<Exception?>(),
Arg.Any<Func<object, Exception?, string>>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.RepublishToRetryQueueAsync(default, default);
.RepublishToRetryQueueAsync(Arg.Any<IChannel>(), Arg.Any<BasicDeliverEventArgs>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.PublishToRetryAsync(default, default, default);
.PublishToRetryAsync(Arg.Any<IChannel>(), Arg.Any<IntegrationMessage>(), Arg.Any<CancellationToken>());
}
[Theory, BitAutoData]
@@ -110,6 +138,7 @@ public class RabbitMqIntegrationListenerServiceTests
_handler.HandleAsync(Arg.Any<string>()).Returns(result);
var expected = IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson());
Assert.NotNull(expected);
await sutProvider.Sut.ProcessReceivedMessageAsync(eventArgs, cancellationToken);
@@ -119,10 +148,17 @@ public class RabbitMqIntegrationListenerServiceTests
Arg.Is(AssertHelper.AssertPropertyEqual(expected, new[] { "DelayUntilDate" })),
Arg.Any<CancellationToken>());
_logger.Received().Log(
LogLevel.Warning,
Arg.Any<EventId>(),
Arg.Is<object>(o => (o.ToString() ?? "").Contains("Max retry attempts reached")),
Arg.Any<Exception?>(),
Arg.Any<Func<object, Exception?, string>>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.RepublishToRetryQueueAsync(default, default);
.RepublishToRetryQueueAsync(Arg.Any<IChannel>(), Arg.Any<BasicDeliverEventArgs>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.PublishToRetryAsync(default, default, default);
.PublishToRetryAsync(Arg.Any<IChannel>(), Arg.Any<IntegrationMessage>(), Arg.Any<CancellationToken>());
}
[Theory, BitAutoData]
@@ -149,6 +185,7 @@ public class RabbitMqIntegrationListenerServiceTests
_handler.HandleAsync(Arg.Any<string>()).Returns(result);
var expected = IntegrationMessage<WebhookIntegrationConfiguration>.FromJson(message.ToJson());
Assert.NotNull(expected);
await sutProvider.Sut.ProcessReceivedMessageAsync(eventArgs, cancellationToken);
@@ -161,9 +198,9 @@ public class RabbitMqIntegrationListenerServiceTests
Arg.Any<CancellationToken>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.RepublishToRetryQueueAsync(default, default);
.RepublishToRetryQueueAsync(Arg.Any<IChannel>(), Arg.Any<BasicDeliverEventArgs>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.PublishToDeadLetterAsync(default, default, default);
.PublishToDeadLetterAsync(Arg.Any<IChannel>(), Arg.Any<IntegrationMessage>(), Arg.Any<CancellationToken>());
}
[Theory, BitAutoData]
@@ -191,11 +228,11 @@ public class RabbitMqIntegrationListenerServiceTests
await _handler.Received(1).HandleAsync(Arg.Is(message.ToJson()));
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.RepublishToRetryQueueAsync(default, default);
.RepublishToRetryQueueAsync(Arg.Any<IChannel>(), Arg.Any<BasicDeliverEventArgs>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.PublishToRetryAsync(default, default, default);
.PublishToRetryAsync(Arg.Any<IChannel>(), Arg.Any<IntegrationMessage>(), Arg.Any<CancellationToken>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.PublishToDeadLetterAsync(default, default, default);
.PublishToDeadLetterAsync(Arg.Any<IChannel>(), Arg.Any<IntegrationMessage>(), Arg.Any<CancellationToken>());
}
[Theory, BitAutoData]
@@ -221,10 +258,10 @@ public class RabbitMqIntegrationListenerServiceTests
await _rabbitMqService.Received(1)
.RepublishToRetryQueueAsync(Arg.Any<IChannel>(), Arg.Any<BasicDeliverEventArgs>());
await _handler.DidNotReceiveWithAnyArgs().HandleAsync(default);
await _handler.DidNotReceiveWithAnyArgs().HandleAsync(Arg.Any<string>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.PublishToRetryAsync(default, default, default);
.PublishToRetryAsync(Arg.Any<IChannel>(), Arg.Any<IntegrationMessage>(), Arg.Any<CancellationToken>());
await _rabbitMqService.DidNotReceiveWithAnyArgs()
.PublishToDeadLetterAsync(default, default, default);
.PublishToDeadLetterAsync(Arg.Any<IChannel>(), Arg.Any<IntegrationMessage>(), Arg.Any<CancellationToken>());
}
}