diff --git a/docs/in-depth/server/index.md b/docs/in-depth/server/index.md index c36e2f4b..f974017b 100644 --- a/docs/in-depth/server/index.md +++ b/docs/in-depth/server/index.md @@ -131,6 +131,7 @@ The options you can set include: * `MaxTop` (int, default: 512000) is the maximum number of items a user can request in a single operation. * `EnableSoftDelete` (bool, default: false) enables soft-delete, which marks items as deleted instead of deleting them from the database. Soft delete allows clients to update their offline cache, but requires that deleted items are purged from the database separately. * `UnauthorizedStatusCode` (int, default: 401 Unauthorized) is the status code returned when the user isn't allowed to do an action. The value must be a client error (4xx) status code in the range 400-499. +* `UnsafeEntityLogging` (bool, default: false) controls how much entity data is written to the logs. When `false`, only the entity ID is logged at `Information` level. When `true`, the entity ID is logged at `Information` level and the full (serialized) entity contents are logged at `Debug` level. Entity contents may include personally identifiable information (PII), secrets, or other sensitive business data, so only enable this option when the additional diagnostic detail is required and the log sink is appropriately secured. ## Configure access permissions diff --git a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Create.cs b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Create.cs index b9b74a42..cb1dd1ae 100644 --- a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Create.cs +++ b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Create.cs @@ -24,14 +24,23 @@ public virtual async Task CreateAsync(CancellationToken cancellat { Logger.LogInformation("CreateAsync"); TEntity entity = await DeserializeJsonContent(cancellationToken).ConfigureAwait(false); - Logger.LogInformation("CreateAsync: {entity}", entity.ToJsonString()); + Logger.LogInformation("CreateAsync: {id}", entity.Id); + if (Options.UnsafeEntityLogging) + { + Logger.LogDebug("CreateAsync: entity {entity}", entity.ToJsonString()); + } await AuthorizeRequestAsync(TableOperation.Create, entity, cancellationToken).ConfigureAwait(false); await AccessControlProvider.PreCommitHookAsync(TableOperation.Create, entity, cancellationToken).ConfigureAwait(false); await Repository.CreateAsync(entity, cancellationToken).ConfigureAwait(false); await PostCommitHookAsync(TableOperation.Create, entity, cancellationToken).ConfigureAwait(false); - Logger.LogInformation("CreateAsync: created {entity}", entity.ToJsonString()); + Logger.LogInformation("CreateAsync: created {id}", entity.Id); + if (Options.UnsafeEntityLogging) + { + Logger.LogDebug("CreateAsync: created entity {entity}", entity.ToJsonString()); + } + return CreatedAtRoute(new { id = entity.Id }, entity); } } diff --git a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Read.cs b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Read.cs index f5f583c4..83086f21 100644 --- a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Read.cs +++ b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Read.cs @@ -42,7 +42,12 @@ public virtual async Task ReadAsync([FromRoute] string id, Cancel Request.ParseConditionalRequest(entity, out _); - Logger.LogInformation("ReadAsync: read {entity}", entity.ToJsonString()); + Logger.LogInformation("ReadAsync: read {id}", entity.Id); + if (Options.UnsafeEntityLogging) + { + Logger.LogDebug("ReadAsync: read entity {entity}", entity.ToJsonString()); + } + return Ok(entity); } } diff --git a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Replace.cs b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Replace.cs index 14ba0e81..2582f8c5 100644 --- a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Replace.cs +++ b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.Replace.cs @@ -23,9 +23,13 @@ public partial class TableController : ODataController where TEntity : [ProducesResponseType(StatusCodes.Status200OK)] public virtual async Task ReplaceAsync([FromRoute] string id, CancellationToken cancellationToken = default) { - Logger.LogInformation("CreateAsync"); + Logger.LogInformation("ReplaceAsync"); TEntity entity = await DeserializeJsonContent(cancellationToken).ConfigureAwait(false); - Logger.LogInformation("ReplaceAsync: {id} {entity}", id, entity.ToJsonString()); + Logger.LogInformation("ReplaceAsync: {id}", id); + if (Options.UnsafeEntityLogging) + { + Logger.LogDebug("ReplaceAsync: {id} entity {entity}", id, entity.ToJsonString()); + } if (id != entity.Id) { @@ -57,7 +61,12 @@ public virtual async Task ReplaceAsync([FromRoute] string id, Can // operation, so we have to do an additional GET to ensure we are getting the right version of the entity TEntity? updatedEntity = await Repository.ReadAsync(id, cancellationToken).ConfigureAwait(false); - Logger.LogInformation("ReplaceAsync: replaced {entity}", updatedEntity.ToJsonString()); + Logger.LogInformation("ReplaceAsync: replaced {id}", updatedEntity?.Id); + if (Options.UnsafeEntityLogging) + { + Logger.LogDebug("ReplaceAsync: replaced entity {entity}", updatedEntity?.ToJsonString() ?? "null"); + } + return Ok(updatedEntity); } } diff --git a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.cs b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.cs index 875083e8..3d59ca5b 100644 --- a/src/CommunityToolkit.Datasync.Server/Controllers/TableController.cs +++ b/src/CommunityToolkit.Datasync.Server/Controllers/TableController.cs @@ -160,7 +160,12 @@ protected virtual async ValueTask AuthorizeRequestAsync(TableOperation operation bool isAuthorized = await AccessControlProvider.IsAuthorizedAsync(operation, entity, cancellationToken).ConfigureAwait(false); if (!isAuthorized) { - Logger.LogWarning("{operation} {entity} statusCode=401 unauthorized", operation, entity?.ToJsonString() ?? ""); + Logger.LogWarning("{operation} {id} statusCode=401 unauthorized", operation, entity?.Id ?? ""); + if (Options.UnsafeEntityLogging) + { + Logger.LogDebug("{operation} entity {entity} statusCode=401 unauthorized", operation, entity?.ToJsonString() ?? ""); + } + throw new HttpException(Options.UnauthorizedStatusCode); } } diff --git a/src/CommunityToolkit.Datasync.Server/Models/TableControllerOptions.cs b/src/CommunityToolkit.Datasync.Server/Models/TableControllerOptions.cs index f6435b2f..ae08da6c 100644 --- a/src/CommunityToolkit.Datasync.Server/Models/TableControllerOptions.cs +++ b/src/CommunityToolkit.Datasync.Server/Models/TableControllerOptions.cs @@ -42,6 +42,19 @@ public class TableControllerOptions /// public bool EnableSoftDelete { get; set; } + /// + /// If true, then the full contents of an entity are serialized into the logs at + /// Debug level and only the entity ID is logged at Information level. If + /// false (the default), only the entity ID is logged at Information level and + /// the full entity contents are never written to the logs. + /// + /// + /// Entity contents may include personally identifiable information (PII), secrets, or other + /// sensitive business data. Only enable this option when the additional diagnostic detail is + /// required and the log sink is appropriately secured. + /// + public bool UnsafeEntityLogging { get; set; } + /// /// The maximum page size for the results returned by a query operation. This is the /// maximum value that the client can specify for the $top query option. diff --git a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Base_Tests.cs b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Base_Tests.cs index 53b78ecd..a060775e 100644 --- a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Base_Tests.cs +++ b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Base_Tests.cs @@ -203,6 +203,41 @@ public async Task AuthorizeRequestAsync_AllowsIfAuthorized() await act.Should().NotThrowAsync(); } + + [Fact] + public async Task AuthorizeRequestAsync_UnsafeEntityLogging_False_LogsIdOnly() + { + IAccessControlProvider provider = FakeAccessControlProvider(TableOperation.Update, false); + IRepository repository = FakeRepository(); + TableControllerOptions options = new() { UnsafeEntityLogging = false }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, provider, options) { Logger = logger }; + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + + Func act = async () => await controller.__AuthorizeRequestAsync(TableOperation.Update, entity, CancellationToken.None); + + (await act.Should().ThrowAsync()).WithStatusCode(401); + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Warning && e.Message.Contains(entity.Id)); + logger.Entries.Should().NotContain(e => e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + logger.Entries.Should().NotContain(e => e.LogLevel == LogLevel.Debug); + } + + [Fact] + public async Task AuthorizeRequestAsync_UnsafeEntityLogging_True_LogsFullEntityAtDebug() + { + IAccessControlProvider provider = FakeAccessControlProvider(TableOperation.Update, false); + IRepository repository = FakeRepository(); + TableControllerOptions options = new() { UnsafeEntityLogging = true }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, provider, options) { Logger = logger }; + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + + Func act = async () => await controller.__AuthorizeRequestAsync(TableOperation.Update, entity, CancellationToken.None); + + (await act.Should().ThrowAsync()).WithStatusCode(401); + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Warning && e.Message.Contains(entity.Id)); + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Debug && e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + } #endregion #region PostCommitHookAsync diff --git a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Create_Tests.cs b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Create_Tests.cs index d22069f8..26fa6bd9 100644 --- a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Create_Tests.cs +++ b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Create_Tests.cs @@ -5,6 +5,7 @@ using CommunityToolkit.Datasync.TestCommon; using CommunityToolkit.Datasync.TestCommon.Models; using Microsoft.AspNetCore.Mvc; +using Microsoft.Extensions.Logging; using NSubstitute; namespace CommunityToolkit.Datasync.Server.Test.Controllers; @@ -12,6 +13,41 @@ namespace CommunityToolkit.Datasync.Server.Test.Controllers; [ExcludeFromCodeCoverage] public class TableController_Create_Tests : BaseTest { + [Fact] + public async Task CreateAsync_UnsafeEntityLogging_False_LogsIdOnly() + { + IAccessControlProvider accessProvider = FakeAccessControlProvider(TableOperation.Create, true); + IRepository repository = FakeRepository(null, false); + TableControllerOptions options = new() { UnsafeEntityLogging = false }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, accessProvider, options) { Logger = logger }; + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + controller.ControllerContext.HttpContext = CreateHttpContext(HttpMethod.Post, "https://localhost/table", entity); + + _ = await controller.CreateAsync(); + + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Information && e.Message.Contains(entity.Id)); + logger.Entries.Should().NotContain(e => e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + logger.Entries.Should().NotContain(e => e.LogLevel == LogLevel.Debug); + } + + [Fact] + public async Task CreateAsync_UnsafeEntityLogging_True_LogsFullEntityAtDebug() + { + IAccessControlProvider accessProvider = FakeAccessControlProvider(TableOperation.Create, true); + IRepository repository = FakeRepository(null, false); + TableControllerOptions options = new() { UnsafeEntityLogging = true }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, accessProvider, options) { Logger = logger }; + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + controller.ControllerContext.HttpContext = CreateHttpContext(HttpMethod.Post, "https://localhost/table", entity); + + _ = await controller.CreateAsync(); + + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Information && e.Message.Contains(entity.Id)); + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Debug && e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + } + [Fact] public async Task CreateAsync_Unauthorized_Throws() { diff --git a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Read_Tests.cs b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Read_Tests.cs index 61ce0b3d..be9497dc 100644 --- a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Read_Tests.cs +++ b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Read_Tests.cs @@ -5,6 +5,7 @@ using CommunityToolkit.Datasync.TestCommon; using CommunityToolkit.Datasync.TestCommon.Models; using Microsoft.AspNetCore.Mvc; +using Microsoft.Extensions.Logging; using NSubstitute; namespace CommunityToolkit.Datasync.Server.Test.Controllers; @@ -12,6 +13,43 @@ namespace CommunityToolkit.Datasync.Server.Test.Controllers; [ExcludeFromCodeCoverage] public class TableController_Read_Tests : BaseTest { + [Fact] + public async Task ReadAsync_UnsafeEntityLogging_False_LogsIdOnly() + { + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + + IAccessControlProvider accessProvider = FakeAccessControlProvider(TableOperation.Read, true); + IRepository repository = FakeRepository(entity, false); + TableControllerOptions options = new() { UnsafeEntityLogging = false }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, accessProvider, options) { Logger = logger }; + controller.ControllerContext.HttpContext = CreateHttpContext(HttpMethod.Get, $"https://localhost/table/{entity.Id}"); + + _ = await controller.ReadAsync(entity.Id); + + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Information && e.Message.Contains(entity.Id)); + logger.Entries.Should().NotContain(e => e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + logger.Entries.Should().NotContain(e => e.LogLevel == LogLevel.Debug); + } + + [Fact] + public async Task ReadAsync_UnsafeEntityLogging_True_LogsFullEntityAtDebug() + { + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + + IAccessControlProvider accessProvider = FakeAccessControlProvider(TableOperation.Read, true); + IRepository repository = FakeRepository(entity, false); + TableControllerOptions options = new() { UnsafeEntityLogging = true }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, accessProvider, options) { Logger = logger }; + controller.ControllerContext.HttpContext = CreateHttpContext(HttpMethod.Get, $"https://localhost/table/{entity.Id}"); + + _ = await controller.ReadAsync(entity.Id); + + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Information && e.Message.Contains(entity.Id)); + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Debug && e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + } + [Fact] public async Task ReadAsync_RepositoryException_Throws() { diff --git a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Replace_Tests.cs b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Replace_Tests.cs index 3ffcccdb..c914a3a0 100644 --- a/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Replace_Tests.cs +++ b/tests/CommunityToolkit.Datasync.Server.Test/Controllers/TableController_Replace_Tests.cs @@ -5,6 +5,7 @@ using CommunityToolkit.Datasync.TestCommon; using CommunityToolkit.Datasync.TestCommon.Models; using Microsoft.AspNetCore.Mvc; +using Microsoft.Extensions.Logging; using NSubstitute; namespace CommunityToolkit.Datasync.Server.Test.Controllers; @@ -12,6 +13,43 @@ namespace CommunityToolkit.Datasync.Server.Test.Controllers; [ExcludeFromCodeCoverage] public class TableController_Replace_Tests : BaseTest { + [Fact] + public async Task ReplaceAsync_UnsafeEntityLogging_False_LogsIdOnly() + { + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + + IAccessControlProvider accessProvider = FakeAccessControlProvider(TableOperation.Update, true); + IRepository repository = FakeRepository(entity, false); + TableControllerOptions options = new() { UnsafeEntityLogging = false }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, accessProvider, options) { Logger = logger }; + controller.ControllerContext.HttpContext = CreateHttpContext(HttpMethod.Put, $"https://localhost/table/{entity.Id}", entity); + + _ = await controller.ReplaceAsync(entity.Id); + + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Information && e.Message.Contains(entity.Id)); + logger.Entries.Should().NotContain(e => e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + logger.Entries.Should().NotContain(e => e.LogLevel == LogLevel.Debug); + } + + [Fact] + public async Task ReplaceAsync_UnsafeEntityLogging_True_LogsFullEntityAtDebug() + { + TableData entity = new() { Id = "0da7fb24-3606-442f-9f68-c47c6e7d09d4" }; + + IAccessControlProvider accessProvider = FakeAccessControlProvider(TableOperation.Update, true); + IRepository repository = FakeRepository(entity, false); + TableControllerOptions options = new() { UnsafeEntityLogging = true }; + CapturingLogger logger = new(); + ExposedTableController controller = new(repository, accessProvider, options) { Logger = logger }; + controller.ControllerContext.HttpContext = CreateHttpContext(HttpMethod.Put, $"https://localhost/table/{entity.Id}", entity); + + _ = await controller.ReplaceAsync(entity.Id); + + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Information && e.Message.Contains(entity.Id)); + logger.Entries.Should().Contain(e => e.LogLevel == LogLevel.Debug && e.Message.Contains("UpdatedAt", StringComparison.OrdinalIgnoreCase)); + } + [Fact] public async Task ReplaceAsync_IdMismatch_Throws() { diff --git a/tests/CommunityToolkit.Datasync.Server.Test/Helpers/CapturingLogger.cs b/tests/CommunityToolkit.Datasync.Server.Test/Helpers/CapturingLogger.cs new file mode 100644 index 00000000..00df493f --- /dev/null +++ b/tests/CommunityToolkit.Datasync.Server.Test/Helpers/CapturingLogger.cs @@ -0,0 +1,50 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +#nullable enable + +using Microsoft.Extensions.Logging; + +namespace CommunityToolkit.Datasync.Server.Test; + +/// +/// A simple implementation that captures every log entry so that +/// tests can assert on the level and rendered message of each log statement. +/// +[ExcludeFromCodeCoverage] +internal sealed class CapturingLogger : ILogger +{ + /// + /// The list of captured log entries, in the order in which they were written. + /// + public List Entries { get; } = []; + + /// + public IDisposable BeginScope(TState state) where TState : notnull => NullScope.Instance; + + /// + public bool IsEnabled(LogLevel logLevel) => true; + + /// + public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) + { + Entries.Add(new LogEntry(logLevel, formatter(state, exception))); + } + + /// + /// A single captured log entry. + /// + /// The level the entry was logged at. + /// The rendered log message. + public sealed record LogEntry(LogLevel LogLevel, string Message); + + private sealed class NullScope : IDisposable + { + public static NullScope Instance { get; } = new(); + + public void Dispose() + { + } + } +} diff --git a/tests/CommunityToolkit.Datasync.Server.Test/Models/TableControllerOptions_Tests.cs b/tests/CommunityToolkit.Datasync.Server.Test/Models/TableControllerOptions_Tests.cs index 00d57587..e34b0e9c 100644 --- a/tests/CommunityToolkit.Datasync.Server.Test/Models/TableControllerOptions_Tests.cs +++ b/tests/CommunityToolkit.Datasync.Server.Test/Models/TableControllerOptions_Tests.cs @@ -18,6 +18,7 @@ public void Ctor_DefaultsDontChange() sut.MaxTop.Should().Be(128000); sut.PageSize.Should().Be(100); sut.UnauthorizedStatusCode.Should().Be(StatusCodes.Status401Unauthorized); + sut.UnsafeEntityLogging.Should().BeFalse(); } [Theory] @@ -60,11 +61,12 @@ public void Ctor_ValidUnauthorizedStatusCode_Roundtrips(int statusCode) [Fact] public void Ctor_Roundtrips() { - TableControllerOptions sut = new() { EnableSoftDelete = true, MaxTop = 100, PageSize = 50, UnauthorizedStatusCode = 403 }; + TableControllerOptions sut = new() { EnableSoftDelete = true, MaxTop = 100, PageSize = 50, UnauthorizedStatusCode = 403, UnsafeEntityLogging = true }; sut.EnableSoftDelete.Should().BeTrue(); sut.MaxTop.Should().Be(100); sut.PageSize.Should().Be(50); sut.UnauthorizedStatusCode.Should().Be(403); + sut.UnsafeEntityLogging.Should().BeTrue(); } }