diff --git a/backend/src/Squidex.Domain.Apps.Entities/Apps/DefaultAppLogStore.cs b/backend/src/Squidex.Domain.Apps.Entities/Apps/DefaultAppLogStore.cs index c70a3d40b..6819a0426 100644 --- a/backend/src/Squidex.Domain.Apps.Entities/Apps/DefaultAppLogStore.cs +++ b/backend/src/Squidex.Domain.Apps.Entities/Apps/DefaultAppLogStore.cs @@ -14,7 +14,6 @@ using System.Threading; using System.Threading.Tasks; using CsvHelper; using CsvHelper.Configuration; -using NodaTime; using Squidex.Infrastructure; using Squidex.Infrastructure.Log.Store; @@ -24,6 +23,7 @@ namespace Squidex.Domain.Apps.Entities.Apps { private const string FieldAuthClientId = "AuthClientId"; private const string FieldAuthUserId = "AuthUserId"; + private const string FieldBytes = "Bytes"; private const string FieldCosts = "Costs"; private const string FieldRequestElapsedMs = "RequestElapsedMs"; private const string FieldRequestMethod = "RequestMethod"; @@ -39,26 +39,27 @@ namespace Squidex.Domain.Apps.Entities.Apps this.requestLogStore = requestLogStore; } - public Task LogAsync(Guid appId, Instant timestamp, string? requestMethod, string? requestPath, string? userId, string? clientId, long elapsedMs, double costs) + public Task LogAsync(Guid appId, RequestLog request) { - var request = new Request + var storedRequest = new Request { Key = appId.ToString(), Properties = new Dictionary { - [FieldCosts] = costs.ToString(CultureInfo.InvariantCulture) + [FieldCosts] = request.Costs.ToString(CultureInfo.InvariantCulture) }, - Timestamp = timestamp + Timestamp = request.Timestamp }; - Append(request, FieldAuthClientId, clientId); - Append(request, FieldAuthUserId, userId); - Append(request, FieldCosts, costs.ToString(CultureInfo.InvariantCulture)); - Append(request, FieldRequestElapsedMs, elapsedMs.ToString(CultureInfo.InvariantCulture)); - Append(request, FieldRequestMethod, requestMethod); - Append(request, FieldRequestPath, requestPath); + Append(storedRequest, FieldAuthClientId, request.UserClientId); + Append(storedRequest, FieldAuthUserId, request.UserId); + Append(storedRequest, FieldBytes, request.Bytes); + Append(storedRequest, FieldCosts, request.Costs); + Append(storedRequest, FieldRequestElapsedMs, request.ElapsedMs); + Append(storedRequest, FieldRequestMethod, request.RequestMethod); + Append(storedRequest, FieldRequestPath, request.RequestPath); - return requestLogStore.LogAsync(request); + return requestLogStore.LogAsync(storedRequest); } public async Task ReadLogAsync(Guid appId, DateTime fromDate, DateTime toDate, Stream stream, CancellationToken ct = default) @@ -77,6 +78,7 @@ namespace Squidex.Domain.Apps.Entities.Apps csv.WriteField(FieldCosts); csv.WriteField(FieldAuthClientId); csv.WriteField(FieldAuthUserId); + csv.WriteField(FieldBytes); await csv.NextRecordAsync(); @@ -89,6 +91,7 @@ namespace Squidex.Domain.Apps.Entities.Apps csv.WriteField(GetDouble(request, FieldCosts)); csv.WriteField(GetString(request, FieldAuthClientId)); csv.WriteField(GetString(request, FieldAuthUserId)); + csv.WriteField(GetString(request, FieldBytes)); await csv.NextRecordAsync(); }, appId.ToString(), fromDate, toDate, ct); @@ -108,6 +111,16 @@ namespace Squidex.Domain.Apps.Entities.Apps } } + private static void Append(Request request, string key, double value) + { + request.Properties[key] = value.ToString(CultureInfo.InvariantCulture); + } + + private static void Append(Request request, string key, long value) + { + request.Properties[key] = value.ToString(CultureInfo.InvariantCulture); + } + private static string GetString(Request request, string key) { return request.Properties.GetValueOrDefault(key, string.Empty)!; diff --git a/backend/src/Squidex.Domain.Apps.Entities/Apps/IAppLogStore.cs b/backend/src/Squidex.Domain.Apps.Entities/Apps/IAppLogStore.cs index 1088ff0de..44ac03f47 100644 --- a/backend/src/Squidex.Domain.Apps.Entities/Apps/IAppLogStore.cs +++ b/backend/src/Squidex.Domain.Apps.Entities/Apps/IAppLogStore.cs @@ -9,13 +9,12 @@ using System; using System.IO; using System.Threading; using System.Threading.Tasks; -using NodaTime; namespace Squidex.Domain.Apps.Entities.Apps { public interface IAppLogStore { - Task LogAsync(Guid appId, Instant timestamp, string? requestMethod, string? requestPath, string? userId, string? clientId, long elapsedMs, double costs); + Task LogAsync(Guid appId, RequestLog request); Task ReadLogAsync(Guid appId, DateTime fromDate, DateTime toDate, Stream stream, CancellationToken ct = default); } diff --git a/backend/src/Squidex.Domain.Apps.Entities/Apps/RequestLog.cs b/backend/src/Squidex.Domain.Apps.Entities/Apps/RequestLog.cs new file mode 100644 index 000000000..f737d90c2 --- /dev/null +++ b/backend/src/Squidex.Domain.Apps.Entities/Apps/RequestLog.cs @@ -0,0 +1,30 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +using NodaTime; + +namespace Squidex.Domain.Apps.Entities.Apps +{ + public struct RequestLog + { + public Instant Timestamp; + + public string? RequestMethod; + + public string? RequestPath; + + public string? UserId; + + public string? UserClientId; + + public long ElapsedMs; + + public long Bytes; + + public double Costs; + } +} diff --git a/backend/src/Squidex.Web/Pipeline/UsageMiddleware.cs b/backend/src/Squidex.Web/Pipeline/UsageMiddleware.cs index 24f993436..4202e8d17 100644 --- a/backend/src/Squidex.Web/Pipeline/UsageMiddleware.cs +++ b/backend/src/Squidex.Web/Pipeline/UsageMiddleware.cs @@ -18,17 +18,17 @@ namespace Squidex.Web.Pipeline { public sealed class UsageMiddleware : IMiddleware { - private readonly IAppLogStore log; + private readonly IAppLogStore logStore; private readonly IApiUsageTracker usageTracker; private readonly IClock clock; - public UsageMiddleware(IAppLogStore log, IApiUsageTracker usageTracker, IClock clock) + public UsageMiddleware(IAppLogStore logStore, IApiUsageTracker usageTracker, IClock clock) { - Guard.NotNull(log, nameof(log)); + Guard.NotNull(logStore, nameof(logStore)); Guard.NotNull(usageTracker, nameof(usageTracker)); Guard.NotNull(clock, nameof(clock)); - this.log = log; + this.logStore = logStore; this.usageTracker = usageTracker; @@ -51,37 +51,37 @@ namespace Squidex.Web.Pipeline { var appId = context.Features.Get()?.AppId; - var costs = context.Features.Get()?.Costs ?? 0; - if (appId != null) { - var elapsedMs = watch.Stop(); - - var now = clock.GetCurrentInstant(); + var bytes = usageBody.BytesWritten; - var userId = context.User.OpenIdSubject(); - var userClient = context.User.OpenIdClientId(); + if (context.Request.ContentLength != null) + { + bytes += context.Request.ContentLength.Value; + } - await log.LogAsync(appId.Id, now, - context.Request.Method, - context.Request.Path, - userId, - userClient, - elapsedMs, - costs); + var request = default(RequestLog); - if (costs > 0) - { - var bytes = usageBody.BytesWritten; + request.Bytes = bytes; + request.Costs = context.Features.Get()?.Costs ?? 0; + request.ElapsedMs = watch.Stop(); + request.RequestMethod = context.Request.Method; + request.RequestPath = context.Request.Path; + request.Timestamp = clock.GetCurrentInstant(); + request.UserClientId = context.User.OpenIdClientId(); + request.UserId = context.User.OpenIdSubject(); - if (context.Request.ContentLength != null) - { - bytes += context.Request.ContentLength.Value; - } + await logStore.LogAsync(appId.Id, request); - var date = now.ToDateTimeUtc().Date; + if (request.Costs > 0) + { + var date = request.Timestamp.ToDateTimeUtc().Date; - await usageTracker.TrackAsync(date, appId.Id.ToString(), userClient, costs, elapsedMs, bytes); + await usageTracker.TrackAsync(date, appId.Id.ToString(), + request.UserClientId, + request.Costs, + request.ElapsedMs, + request.Bytes); } } } diff --git a/backend/src/Squidex.Web/Pipeline/UsageStream.cs b/backend/src/Squidex.Web/Pipeline/UsageStream.cs index 4268008ee..2e878945a 100644 --- a/backend/src/Squidex.Web/Pipeline/UsageStream.cs +++ b/backend/src/Squidex.Web/Pipeline/UsageStream.cs @@ -64,7 +64,7 @@ namespace Squidex.Web.Pipeline public override async Task WriteAsync(byte[] buffer, int offset, int count, CancellationToken cancellationToken) { - await base.WriteAsync(buffer, offset, count, cancellationToken); + await inner.WriteAsync(buffer, offset, count, cancellationToken); bytesWritten += count; } @@ -78,7 +78,7 @@ namespace Squidex.Web.Pipeline public override async ValueTask WriteAsync(ReadOnlyMemory buffer, CancellationToken cancellationToken = default) { - await base.WriteAsync(buffer, cancellationToken); + await inner.WriteAsync(buffer, cancellationToken); bytesWritten += buffer.Length; } diff --git a/backend/tests/Squidex.Domain.Apps.Entities.Tests/Apps/DefaultAppLogStoreTests.cs b/backend/tests/Squidex.Domain.Apps.Entities.Tests/Apps/DefaultAppLogStoreTests.cs index a293a48f0..12c003cf7 100644 --- a/backend/tests/Squidex.Domain.Apps.Entities.Tests/Apps/DefaultAppLogStoreTests.cs +++ b/backend/tests/Squidex.Domain.Apps.Entities.Tests/Apps/DefaultAppLogStoreTests.cs @@ -33,22 +33,27 @@ namespace Squidex.Domain.Apps.Entities.Apps A.CallTo(() => requestLogStore.LogAsync(A._)) .Invokes((Request request) => recordedRequest = request); - var clientId = "frontend"; - var costs = 2; - var elapsedMs = 120; - var requestMethod = "GET"; - var requestPath = "/my-path"; - var userId = "user1"; - - await sut.LogAsync(Guid.NewGuid(), default, requestMethod, requestPath, userId, clientId, elapsedMs, costs); + var request = default(RequestLog); + request.Bytes = 1024; + request.Costs = 1.5; + request.ElapsedMs = 120; + request.RequestMethod = "GET"; + request.RequestPath = "/my-path"; + request.Timestamp = default; + request.UserClientId = "frontend"; + request.UserId = "user1"; + + await sut.LogAsync(Guid.NewGuid(), request); Assert.NotNull(recordedRequest); - Assert.Contains(clientId, recordedRequest!.Properties.Values); - Assert.Contains(costs.ToString(), recordedRequest!.Properties.Values); - Assert.Contains(elapsedMs.ToString(), recordedRequest!.Properties.Values); - Assert.Contains(requestMethod, recordedRequest!.Properties.Values); - Assert.Contains(requestPath, recordedRequest!.Properties.Values); + Assert.Contains(request.Bytes.ToString(), recordedRequest!.Properties.Values); + Assert.Contains(request.Costs.ToString(), recordedRequest!.Properties.Values); + Assert.Contains(request.ElapsedMs.ToString(), recordedRequest!.Properties.Values); + Assert.Contains(request.RequestMethod, recordedRequest!.Properties.Values); + Assert.Contains(request.RequestPath, recordedRequest!.Properties.Values); + Assert.Contains(request.UserClientId, recordedRequest!.Properties.Values); + Assert.Contains(request.UserId, recordedRequest!.Properties.Values); } [Fact] diff --git a/backend/tests/Squidex.Web.Tests/Pipeline/UsageMiddlewareTests.cs b/backend/tests/Squidex.Web.Tests/Pipeline/UsageMiddlewareTests.cs index 2cbdad475..6eb71bea5 100644 --- a/backend/tests/Squidex.Web.Tests/Pipeline/UsageMiddlewareTests.cs +++ b/backend/tests/Squidex.Web.Tests/Pipeline/UsageMiddlewareTests.cs @@ -6,6 +6,8 @@ // ========================================================================== using System; +using System.IO; +using System.Text; using System.Threading.Tasks; using FakeItEasy; using Microsoft.AspNetCore.Http; @@ -15,6 +17,8 @@ using Squidex.Infrastructure; using Squidex.Infrastructure.UsageTracking; using Xunit; +#pragma warning disable RECS0018 // Comparison of floating point numbers with equality operator + namespace Squidex.Web.Pipeline { public class UsageMiddlewareTests @@ -109,14 +113,35 @@ namespace Squidex.Web.Pipeline } [Fact] - public async Task Should_track_response_bytes() + public async Task Should_track_response_bytes_with_writer() + { + httpContext.Features.Set(new AppFeature(appId)); + httpContext.Features.Set(new ApiCostsAttribute(13)); + + await sut.InvokeAsync(httpContext, async x => + { + await x.Response.BodyWriter.WriteAsync(Encoding.Default.GetBytes("Hello World")); + + await next(x); + }); + + Assert.True(isNextCalled); + + var date = instant.ToDateTimeUtc().Date; + + A.CallTo(() => usageTracker.TrackAsync(date, A._, A._, 13, A._, 11)) + .MustHaveHappened(); + } + + [Fact] + public async Task Should_track_response_bytes_with_stream() { httpContext.Features.Set(new AppFeature(appId)); httpContext.Features.Set(new ApiCostsAttribute(13)); await sut.InvokeAsync(httpContext, async x => { - await x.Response.WriteAsync("Hello World"); + await x.Response.Body.WriteAsync(Encoding.Default.GetBytes("Hello World")); await next(x); }); @@ -129,6 +154,37 @@ namespace Squidex.Web.Pipeline .MustHaveHappened(); } + [Fact] + public async Task Should_track_response_bytes_with_file() + { + httpContext.Features.Set(new AppFeature(appId)); + httpContext.Features.Set(new ApiCostsAttribute(13)); + + var tempFileName = Path.GetTempFileName(); + try + { + File.WriteAllText(tempFileName, "Hello World"); + + await sut.InvokeAsync(httpContext, async x => + { + await x.Response.SendFileAsync(tempFileName, 0, new FileInfo(tempFileName).Length); + + await next(x); + }); + } + finally + { + File.Delete(tempFileName); + } + + Assert.True(isNextCalled); + + var date = instant.ToDateTimeUtc().Date; + + A.CallTo(() => usageTracker.TrackAsync(date, A._, A._, 13, A._, 11)) + .MustHaveHappened(); + } + [Fact] public async Task Should_not_track_if_costs_are_zero() { @@ -156,7 +212,12 @@ namespace Squidex.Web.Pipeline await sut.InvokeAsync(httpContext, next); - A.CallTo(() => appLogStore.LogAsync(appId.Id, instant, "GET", "/my-path", null, null, A._, 0)) + A.CallTo(() => appLogStore.LogAsync(appId.Id, + A.That.Matches(x => + x.Timestamp == instant && + x.RequestMethod == "GET" && + x.RequestPath == "/my-path" && + x.Costs == 0))) .MustHaveHappened(); } }