From d69db26143da85831bb934149be91a74335d9e09 Mon Sep 17 00:00:00 2001 From: Sebastian Date: Mon, 23 Apr 2018 16:36:38 +0200 Subject: [PATCH] Profiler --- Squidex.ruleset | 1 + .../AppProvider.cs | 140 +++++++++++------- .../Squidex.Domain.Apps.Entities.csproj | 1 + .../CachingProviderBase.cs | 2 +- .../Commands/DomainObjectGrain.cs | 3 +- .../Log/Adapter/SemanticLogLogger.cs | 9 -- .../Log/ILogProfilerSessionProvider.cs | 14 ++ .../Log/NoopDisposable.cs | 24 +++ src/Squidex.Infrastructure/Log/Profile.cs | 67 +++++++++ .../Log/ProfilerSession.cs | 58 ++++++++ src/Squidex.Infrastructure/Orleans/J{T}.cs | 50 ++++--- .../UsageTracking/BackgroundUsageTracker.cs | 2 + .../UsageTracking/CachingUsageTracker.cs | 56 +++++++ .../Config/Domain/InfrastructureServices.cs | 4 + src/Squidex/Config/Domain/LoggingServices.cs | 4 + src/Squidex/Config/Logging.cs | 7 +- src/Squidex/Config/Orleans/SiloWrapper.cs | 2 +- src/Squidex/Config/Web/WebExtensions.cs | 2 +- src/Squidex/Config/Web/WebServices.cs | 10 +- src/Squidex/Pipeline/ApiCostsFilter.cs | 16 +- ....cs => RequestLogPerformanceMiddleware.cs} | 26 +++- .../RequestLogProfilerSessionProvider.cs | 40 +++++ src/Squidex/Program.cs | 2 +- .../ThreadingUsageTrackerTests.cs | 62 ++++++++ 24 files changed, 493 insertions(+), 109 deletions(-) rename src/{Squidex.Domain.Apps.Entities => Squidex.Infrastructure}/CachingProviderBase.cs (95%) create mode 100644 src/Squidex.Infrastructure/Log/ILogProfilerSessionProvider.cs create mode 100644 src/Squidex.Infrastructure/Log/NoopDisposable.cs create mode 100644 src/Squidex.Infrastructure/Log/Profile.cs create mode 100644 src/Squidex.Infrastructure/Log/ProfilerSession.cs create mode 100644 src/Squidex.Infrastructure/UsageTracking/CachingUsageTracker.cs rename src/Squidex/Pipeline/{LogPerformanceMiddleware.cs => RequestLogPerformanceMiddleware.cs} (51%) create mode 100644 src/Squidex/Pipeline/RequestLogProfilerSessionProvider.cs create mode 100644 tests/Squidex.Infrastructure.Tests/UsageTracking/ThreadingUsageTrackerTests.cs diff --git a/Squidex.ruleset b/Squidex.ruleset index 6c96f8b6b..20a67c5f9 100644 --- a/Squidex.ruleset +++ b/Squidex.ruleset @@ -81,6 +81,7 @@ + \ No newline at end of file diff --git a/src/Squidex.Domain.Apps.Entities/AppProvider.cs b/src/Squidex.Domain.Apps.Entities/AppProvider.cs index 1ee45a522..739b82e64 100644 --- a/src/Squidex.Domain.Apps.Entities/AppProvider.cs +++ b/src/Squidex.Domain.Apps.Entities/AppProvider.cs @@ -17,6 +17,7 @@ using Squidex.Domain.Apps.Entities.Rules.Repositories; using Squidex.Domain.Apps.Entities.Schemas; using Squidex.Domain.Apps.Entities.Schemas.Repositories; using Squidex.Infrastructure; +using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Orleans; namespace Squidex.Domain.Apps.Entities @@ -47,107 +48,134 @@ namespace Squidex.Domain.Apps.Entities public async Task<(IAppEntity, ISchemaEntity)> GetAppWithSchemaAsync(Guid appId, Guid id) { - var app = await grainFactory.GetGrain(appId).GetStateAsync(); - - if (!IsExisting(app)) + using (Profile.Method()) { - return (null, null); - } + var app = await grainFactory.GetGrain(appId).GetStateAsync(); - var schema = await grainFactory.GetGrain(id).GetStateAsync(); + if (!IsExisting(app)) + { + return (null, null); + } - if (!IsExisting(schema, false)) - { - return (null, null); - } + var schema = await grainFactory.GetGrain(id).GetStateAsync(); + + if (!IsExisting(schema, false)) + { + return (null, null); + } - return (app.Value, schema.Value); + return (app.Value, schema.Value); + } } public async Task GetAppAsync(string appName) { - var appId = await GetAppIdAsync(appName); - - if (appId == Guid.Empty) + using (Profile.Method()) { - return null; - } + var appId = await GetAppIdAsync(appName); - var app = await grainFactory.GetGrain(appId).GetStateAsync(); + if (appId == Guid.Empty) + { + return null; + } - if (!IsExisting(app)) - { - return null; - } + var app = await grainFactory.GetGrain(appId).GetStateAsync(); - return app.Value; + if (!IsExisting(app)) + { + return null; + } + + return app.Value; + } } public async Task GetSchemaAsync(Guid appId, string name) { - var schemaId = await GetSchemaIdAsync(appId, name); - - if (schemaId == Guid.Empty) + using (Profile.Method()) { - return null; - } + var schemaId = await GetSchemaIdAsync(appId, name); + + if (schemaId == Guid.Empty) + { + return null; + } - return await GetSchemaAsync(appId, schemaId, false); + return await GetSchemaAsync(appId, schemaId, false); + } } public async Task GetSchemaAsync(Guid appId, Guid id, bool allowDeleted = false) { - var schema = await grainFactory.GetGrain(id).GetStateAsync(); - - if (!IsExisting(schema, allowDeleted) || schema.Value.AppId.Id != appId) + using (Profile.Method()) { - return null; - } + var schema = await grainFactory.GetGrain(id).GetStateAsync(); + + if (!IsExisting(schema, allowDeleted) || schema.Value.AppId.Id != appId) + { + return null; + } - return schema.Value; + return schema.Value; + } } public async Task> GetSchemasAsync(Guid appId) { - var ids = await schemaRepository.QuerySchemaIdsAsync(appId); + using (Profile.Method()) + { + var ids = await schemaRepository.QuerySchemaIdsAsync(appId); - var schemas = - await Task.WhenAll( - ids.Select(id => grainFactory.GetGrain(id).GetStateAsync())); + var schemas = + await Task.WhenAll( + ids.Select(id => grainFactory.GetGrain(id).GetStateAsync())); - return schemas.Where(s => IsFound(s.Value)).Select(s => s.Value).ToList(); + return schemas.Where(s => IsFound(s.Value)).Select(s => s.Value).ToList(); + } } public async Task> GetRulesAsync(Guid appId) { - var ids = await ruleRepository.QueryRuleIdsAsync(appId); + using (Profile.Method()) + { + var ids = await ruleRepository.QueryRuleIdsAsync(appId); - var rules = - await Task.WhenAll( - ids.Select(id => grainFactory.GetGrain(id).GetStateAsync())); + var rules = + await Task.WhenAll( + ids.Select(id => grainFactory.GetGrain(id).GetStateAsync())); - return rules.Where(r => IsFound(r.Value)).Select(r => r.Value).ToList(); + return rules.Where(r => IsFound(r.Value)).Select(r => r.Value).ToList(); + } } public async Task> GetUserApps(string userId) { - var ids = await appRepository.QueryUserAppIdsAsync(userId); + using (Profile.Method()) + { + var ids = await appRepository.QueryUserAppIdsAsync(userId); - var apps = - await Task.WhenAll( - ids.Select(id => grainFactory.GetGrain(id).GetStateAsync())); + var apps = + await Task.WhenAll( + ids.Select(id => grainFactory.GetGrain(id).GetStateAsync())); - return apps.Where(a => IsFound(a.Value)).Select(a => a.Value).ToList(); + return apps.Where(a => IsFound(a.Value)).Select(a => a.Value).ToList(); + } } - private Task GetAppIdAsync(string name) + private async Task GetAppIdAsync(string name) { - return appRepository.FindAppIdByNameAsync(name); + using (Profile.Method()) + { + return await appRepository.FindAppIdByNameAsync(name); + } } private async Task GetSchemaIdAsync(Guid appId, string name) { - return await schemaRepository.FindSchemaIdAsync(appId, name); + using (Profile.Method()) + { + return await schemaRepository.FindSchemaIdAsync(appId, name); + } } private static bool IsFound(IEntityWithVersion entity) @@ -155,14 +183,14 @@ namespace Squidex.Domain.Apps.Entities return entity.Version > EtagVersion.Empty; } - private static bool IsExisting(J schema, bool allowDeleted) + private static bool IsExisting(J app) { - return IsFound(schema.Value) && (!schema.Value.IsDeleted || allowDeleted); + return IsFound(app.Value) && !app.Value.IsArchived; } - private static bool IsExisting(J app) + private static bool IsExisting(J schema, bool allowDeleted) { - return IsFound(app.Value) && !app.Value.IsArchived; + return IsFound(schema.Value) && (!schema.Value.IsDeleted || allowDeleted); } } } diff --git a/src/Squidex.Domain.Apps.Entities/Squidex.Domain.Apps.Entities.csproj b/src/Squidex.Domain.Apps.Entities/Squidex.Domain.Apps.Entities.csproj index 312ada30a..710bcc1e1 100644 --- a/src/Squidex.Domain.Apps.Entities/Squidex.Domain.Apps.Entities.csproj +++ b/src/Squidex.Domain.Apps.Entities/Squidex.Domain.Apps.Entities.csproj @@ -15,6 +15,7 @@ + diff --git a/src/Squidex.Domain.Apps.Entities/CachingProviderBase.cs b/src/Squidex.Infrastructure/CachingProviderBase.cs similarity index 95% rename from src/Squidex.Domain.Apps.Entities/CachingProviderBase.cs rename to src/Squidex.Infrastructure/CachingProviderBase.cs index 996646fe8..c96cdfdbe 100644 --- a/src/Squidex.Domain.Apps.Entities/CachingProviderBase.cs +++ b/src/Squidex.Infrastructure/CachingProviderBase.cs @@ -8,7 +8,7 @@ using Microsoft.Extensions.Caching.Memory; using Squidex.Infrastructure; -namespace Squidex.Domain.Apps.Entities +namespace Squidex.Infrastructure { public abstract class CachingProviderBase { diff --git a/src/Squidex.Infrastructure/Commands/DomainObjectGrain.cs b/src/Squidex.Infrastructure/Commands/DomainObjectGrain.cs index 339c2ebd6..6947927df 100644 --- a/src/Squidex.Infrastructure/Commands/DomainObjectGrain.cs +++ b/src/Squidex.Infrastructure/Commands/DomainObjectGrain.cs @@ -162,7 +162,8 @@ namespace Squidex.Infrastructure.Commands throw new DomainObjectNotFoundException(id.ToString(), GetType()); } - else if (!isUpdate && Version >= 0) + + if (!isUpdate && Version >= 0) { throw new DomainException("Object has already been created."); } diff --git a/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs index 3a914d6cc..3842f2e2a 100644 --- a/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs +++ b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs @@ -86,14 +86,5 @@ namespace Squidex.Infrastructure.Log.Adapter { return NoopDisposable.Instance; } - - private class NoopDisposable : IDisposable - { - public static readonly NoopDisposable Instance = new NoopDisposable(); - - public void Dispose() - { - } - } } } diff --git a/src/Squidex.Infrastructure/Log/ILogProfilerSessionProvider.cs b/src/Squidex.Infrastructure/Log/ILogProfilerSessionProvider.cs new file mode 100644 index 000000000..a0b2d8a16 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ILogProfilerSessionProvider.cs @@ -0,0 +1,14 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +namespace Squidex.Infrastructure.Log +{ + public interface ILogProfilerSessionProvider + { + ProfilerSession GetSession(); + } +} diff --git a/src/Squidex.Infrastructure/Log/NoopDisposable.cs b/src/Squidex.Infrastructure/Log/NoopDisposable.cs new file mode 100644 index 000000000..60d95e7a0 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/NoopDisposable.cs @@ -0,0 +1,24 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +using System; + +namespace Squidex.Infrastructure.Log +{ + public sealed class NoopDisposable : IDisposable + { + public static readonly NoopDisposable Instance = new NoopDisposable(); + + private NoopDisposable() + { + } + + public void Dispose() + { + } + } +} diff --git a/src/Squidex.Infrastructure/Log/Profile.cs b/src/Squidex.Infrastructure/Log/Profile.cs new file mode 100644 index 000000000..ce7cc058c --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Profile.cs @@ -0,0 +1,67 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +using System; +using System.Diagnostics; +using System.Runtime.CompilerServices; + +namespace Squidex.Infrastructure.Log +{ + public static class Profile + { + private static ILogProfilerSessionProvider sessionProvider; + + private sealed class Timer : IDisposable + { + private readonly Stopwatch watch = Stopwatch.StartNew(); + private readonly ProfilerSession session; + private readonly string key; + + public Timer(ProfilerSession session, string key) + { + this.session = session; + this.key = key; + } + + public void Dispose() + { + watch.Stop(); + + session.Measured(key, watch.ElapsedMilliseconds); + } + } + + public static void Init(ILogProfilerSessionProvider provider) + { + sessionProvider = provider; + } + + public static IDisposable Method([CallerMemberName] string memberName = null) + { + return Key($"{typeof(T).Name}/{memberName}"); + } + + public static IDisposable Method(string objectName, [CallerMemberName] string memberName = null) + { + return Key($"{objectName}/{memberName}"); + } + + public static IDisposable Key(string key) + { + Guard.NotNull(key, nameof(key)); + + var session = sessionProvider?.GetSession(); + + if (session == null) + { + return NoopDisposable.Instance; + } + + return new Timer(session, key); + } + } +} diff --git a/src/Squidex.Infrastructure/Log/ProfilerSession.cs b/src/Squidex.Infrastructure/Log/ProfilerSession.cs new file mode 100644 index 000000000..9249b630e --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ProfilerSession.cs @@ -0,0 +1,58 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +using System.Collections.Concurrent; + +namespace Squidex.Infrastructure.Log +{ + public sealed class ProfilerSession + { + private struct ProfilerItem + { + public long Total; + public long Count; + } + + private readonly ConcurrentDictionary traces = new ConcurrentDictionary(); + + public void Measured(string name, long elapsed) + { + Guard.NotNullOrEmpty(name, nameof(name)); + + traces.AddOrUpdate(name, x => + { + return new ProfilerItem { Total = elapsed, Count = 1 }; + }, + (x, result) => + { + result.Total += elapsed; + result.Count++; + + return result; + }); + } + + public void Write(IObjectWriter writer) + { + Guard.NotNull(writer, nameof(writer)); + + if (traces.Count > 0) + { + writer.WriteObject("profiler", p => + { + foreach (var kvp in traces) + { + p.WriteObject(kvp.Key, k => k + .WriteProperty("elapsedMsTotal", kvp.Value.Total) + .WriteProperty("elapsedMsAvg", kvp.Value.Total / kvp.Value.Count) + .WriteProperty("count", kvp.Value.Count)); + } + }); + } + } + } +} diff --git a/src/Squidex.Infrastructure/Orleans/J{T}.cs b/src/Squidex.Infrastructure/Orleans/J{T}.cs index c6f28cd45..f9d9232a8 100644 --- a/src/Squidex.Infrastructure/Orleans/J{T}.cs +++ b/src/Squidex.Infrastructure/Orleans/J{T}.cs @@ -11,27 +11,23 @@ using System.Threading.Tasks; using Newtonsoft.Json; using Orleans.CodeGeneration; using Orleans.Serialization; +using Squidex.Infrastructure.Log; namespace Squidex.Infrastructure.Orleans { public struct J { - private readonly T value; - - public T Value - { - get { return value; } - } + public T Value { get; } [JsonConstructor] public J(T value) { - this.value = value; + Value = value; } public static implicit operator T(J value) { - return value.value; + return value.Value; } public static implicit operator J(T d) @@ -41,7 +37,7 @@ namespace Squidex.Infrastructure.Orleans public override string ToString() { - return value?.ToString() ?? string.Empty; + return Value?.ToString() ?? string.Empty; } public static Task> AsTask(T value) @@ -58,32 +54,38 @@ namespace Squidex.Infrastructure.Orleans [SerializerMethod] public static void Serialize(object input, ISerializationContext context, Type expected) { - var stream = new MemoryStream(); - - using (var writer = new JsonTextWriter(new StreamWriter(stream))) + using (Profile.Method(nameof(J))) { - J.Serializer.Serialize(writer, input); + var stream = new MemoryStream(); - writer.Flush(); - } + using (var writer = new JsonTextWriter(new StreamWriter(stream))) + { + J.Serializer.Serialize(writer, input); - var outBytes = stream.ToArray(); + writer.Flush(); + } - context.StreamWriter.Write(outBytes.Length); - context.StreamWriter.Write(outBytes); + var outBytes = stream.ToArray(); + + context.StreamWriter.Write(outBytes.Length); + context.StreamWriter.Write(outBytes); + } } [DeserializerMethod] public static object Deserialize(Type expected, IDeserializationContext context) { - var outLength = context.StreamReader.ReadInt(); - var outBytes = context.StreamReader.ReadBytes(outLength); + using (Profile.Method(nameof(J))) + { + var outLength = context.StreamReader.ReadInt(); + var outBytes = context.StreamReader.ReadBytes(outLength); - var stream = new MemoryStream(outBytes); + var stream = new MemoryStream(outBytes); - using (var reader = new JsonTextReader(new StreamReader(stream))) - { - return J.Serializer.Deserialize(reader, expected); + using (var reader = new JsonTextReader(new StreamReader(stream))) + { + return J.Serializer.Deserialize(reader, expected); + } } } } diff --git a/src/Squidex.Infrastructure/UsageTracking/BackgroundUsageTracker.cs b/src/Squidex.Infrastructure/UsageTracking/BackgroundUsageTracker.cs index 17d06b573..193343f6a 100644 --- a/src/Squidex.Infrastructure/UsageTracking/BackgroundUsageTracker.cs +++ b/src/Squidex.Infrastructure/UsageTracking/BackgroundUsageTracker.cs @@ -110,6 +110,8 @@ namespace Squidex.Infrastructure.UsageTracking public async Task GetMonthlyCallsAsync(string key, DateTime date) { + Guard.NotNull(key, nameof(key)); + ThrowIfDisposed(); var dateFrom = new DateTime(date.Year, date.Month, 1); diff --git a/src/Squidex.Infrastructure/UsageTracking/CachingUsageTracker.cs b/src/Squidex.Infrastructure/UsageTracking/CachingUsageTracker.cs new file mode 100644 index 000000000..2f287d7db --- /dev/null +++ b/src/Squidex.Infrastructure/UsageTracking/CachingUsageTracker.cs @@ -0,0 +1,56 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +using System; +using System.Collections.Generic; +using System.Threading.Tasks; +using Microsoft.Extensions.Caching.Memory; + +namespace Squidex.Infrastructure.UsageTracking +{ + public sealed class CachingUsageTracker : CachingProviderBase, IUsageTracker + { + private static readonly TimeSpan CacheTime = TimeSpan.FromMinutes(10); + private readonly IUsageTracker inner; + + public CachingUsageTracker(IUsageTracker inner, IMemoryCache cache) + : base(cache) + { + Guard.NotNull(inner, nameof(inner)); + + this.inner = inner; + } + + public Task> QueryAsync(string key, DateTime fromDate, DateTime toDate) + { + return inner.QueryAsync(key, fromDate, toDate); + } + + public Task TrackAsync(string key, double weight, double elapsedMs) + { + return inner.TrackAsync(key, weight, elapsedMs); + } + + public async Task GetMonthlyCallsAsync(string key, DateTime date) + { + Guard.NotNull(key, nameof(key)); + + var cacheKey = string.Concat(key, date); + + if (Cache.TryGetValue(cacheKey, out var result)) + { + return result; + } + + result = await inner.GetMonthlyCallsAsync(key, date); + + Cache.Set(cacheKey, result, CacheTime); + + return result; + } + } +} diff --git a/src/Squidex/Config/Domain/InfrastructureServices.cs b/src/Squidex/Config/Domain/InfrastructureServices.cs index 5734ecf20..b1fbb1c7d 100644 --- a/src/Squidex/Config/Domain/InfrastructureServices.cs +++ b/src/Squidex/Config/Domain/InfrastructureServices.cs @@ -8,6 +8,7 @@ using System; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Mvc.Infrastructure; +using Microsoft.Extensions.Caching.Memory; using Microsoft.Extensions.DependencyInjection; using NodaTime; using Squidex.Infrastructure; @@ -25,6 +26,9 @@ namespace Squidex.Config.Domain .As(); services.AddSingletonAs() + .AsSelf(); + + services.AddSingletonAs(c => new CachingUsageTracker(c.GetRequiredService(), c.GetRequiredService())) .As(); services.AddSingletonAs() diff --git a/src/Squidex/Config/Domain/LoggingServices.cs b/src/Squidex/Config/Domain/LoggingServices.cs index e4ee51850..6306018b9 100644 --- a/src/Squidex/Config/Domain/LoggingServices.cs +++ b/src/Squidex/Config/Domain/LoggingServices.cs @@ -59,6 +59,10 @@ namespace Squidex.Config.Domain services.AddSingletonAs() .As(); + + services.AddSingletonAs() + .As() + .AsSelf(); } } } diff --git a/src/Squidex/Config/Logging.cs b/src/Squidex/Config/Logging.cs index 9fa6e3b05..ecd1c0859 100644 --- a/src/Squidex/Config/Logging.cs +++ b/src/Squidex/Config/Logging.cs @@ -12,7 +12,7 @@ namespace Squidex.Config { public static class Logging { - public static void AddOrleansFilter(this ILoggingBuilder builder) + public static void AddFilter(this ILoggingBuilder builder) { builder.AddFilter((category, level) => { @@ -26,6 +26,11 @@ namespace Squidex.Config return level >= LogLevel.Warning; } + if (category.StartsWith("Microsoft.AspNetCore.", StringComparison.OrdinalIgnoreCase)) + { + return level > LogLevel.Information; + } + return level >= LogLevel.Information; }); } diff --git a/src/Squidex/Config/Orleans/SiloWrapper.cs b/src/Squidex/Config/Orleans/SiloWrapper.cs index 3a5a416c0..dd9593d99 100644 --- a/src/Squidex/Config/Orleans/SiloWrapper.cs +++ b/src/Squidex/Config/Orleans/SiloWrapper.cs @@ -75,7 +75,7 @@ namespace Squidex.Config.Orleans { builder.AddConfiguration(hostingContext.Configuration.GetSection("logging")); builder.AddSemanticLog(); - builder.AddOrleansFilter(); + builder.AddFilter(); }) .ConfigureApplicationParts(builder => { diff --git a/src/Squidex/Config/Web/WebExtensions.cs b/src/Squidex/Config/Web/WebExtensions.cs index c03981f17..744b6adf3 100644 --- a/src/Squidex/Config/Web/WebExtensions.cs +++ b/src/Squidex/Config/Web/WebExtensions.cs @@ -15,7 +15,7 @@ namespace Squidex.Config.Web { public static IApplicationBuilder UseMyTracking(this IApplicationBuilder app) { - app.UseMiddleware(); + app.UseMiddleware(); return app; } diff --git a/src/Squidex/Config/Web/WebServices.cs b/src/Squidex/Config/Web/WebServices.cs index f3177c84d..ec2b3a0cf 100644 --- a/src/Squidex/Config/Web/WebServices.cs +++ b/src/Squidex/Config/Web/WebServices.cs @@ -15,10 +15,14 @@ namespace Squidex.Config.Web { public static void AddMyMvc(this IServiceCollection services) { - services.AddSingletonAs(); + services.AddSingletonAs() + .AsSelf(); - services.AddSingletonAs(); - services.AddSingletonAs(); + services.AddSingletonAs() + .AsSelf(); + + services.AddSingletonAs() + .AsSelf(); services.AddMvc().AddMySerializers(); services.AddCors(); diff --git a/src/Squidex/Pipeline/ApiCostsFilter.cs b/src/Squidex/Pipeline/ApiCostsFilter.cs index b01a3d766..a4161e29c 100644 --- a/src/Squidex/Pipeline/ApiCostsFilter.cs +++ b/src/Squidex/Pipeline/ApiCostsFilter.cs @@ -11,6 +11,7 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Mvc; using Microsoft.AspNetCore.Mvc.Filters; using Squidex.Domain.Apps.Entities.Apps.Services; +using Squidex.Infrastructure.Log; using Squidex.Infrastructure.UsageTracking; namespace Squidex.Pipeline @@ -47,14 +48,17 @@ namespace Squidex.Pipeline if (appFeature?.App != null && FilterDefinition.Weight > 0) { - var plan = appPlanProvider.GetPlanForApp(appFeature.App); + using (Profile.Key("CheckUsage")) + { + var plan = appPlanProvider.GetPlanForApp(appFeature.App); - var usage = await usageTracker.GetMonthlyCallsAsync(appFeature.App.Id.ToString(), DateTime.Today); + var usage = await usageTracker.GetMonthlyCallsAsync(appFeature.App.Id.ToString(), DateTime.Today); - if (plan.MaxApiCalls >= 0 && usage > plan.MaxApiCalls * 1.1) - { - context.Result = new StatusCodeResult(429); - return; + if (plan.MaxApiCalls >= 0 && usage > plan.MaxApiCalls * 1.1) + { + context.Result = new StatusCodeResult(429); + return; + } } var stopWatch = Stopwatch.StartNew(); diff --git a/src/Squidex/Pipeline/LogPerformanceMiddleware.cs b/src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs similarity index 51% rename from src/Squidex/Pipeline/LogPerformanceMiddleware.cs rename to src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs index 166e18b51..76c381b13 100644 --- a/src/Squidex/Pipeline/LogPerformanceMiddleware.cs +++ b/src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs @@ -13,13 +13,15 @@ using Squidex.Infrastructure.Log; namespace Squidex.Pipeline { - public sealed class LogPerformanceMiddleware : ActionFilterAttribute + public sealed class RequestLogPerformanceMiddleware : ActionFilterAttribute { + private readonly RequestLogProfilerSessionProvider requestSession; private readonly RequestDelegate next; private readonly ISemanticLog log; - public LogPerformanceMiddleware(RequestDelegate next, ISemanticLog log) + public RequestLogPerformanceMiddleware(RequestLogProfilerSessionProvider requestSession, RequestDelegate next, ISemanticLog log) { + this.requestSession = requestSession; this.next = next; this.log = log; } @@ -28,11 +30,25 @@ namespace Squidex.Pipeline { var stopWatch = Stopwatch.StartNew(); - await next(context); + var session = new ProfilerSession(); - stopWatch.Stop(); + try + { + requestSession.Start(context, session); - log.LogInformation(w => w.WriteProperty("elapsedRequestMs", stopWatch.ElapsedMilliseconds)); + await next(context); + } + finally + { + stopWatch.Stop(); + + log.LogInformation(w => + { + session.Write(w); + + w.WriteProperty("elapsedRequestMs", stopWatch.ElapsedMilliseconds); + }); + } } } } diff --git a/src/Squidex/Pipeline/RequestLogProfilerSessionProvider.cs b/src/Squidex/Pipeline/RequestLogProfilerSessionProvider.cs new file mode 100644 index 000000000..d4805f663 --- /dev/null +++ b/src/Squidex/Pipeline/RequestLogProfilerSessionProvider.cs @@ -0,0 +1,40 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +using Microsoft.AspNetCore.Http; +using Squidex.Infrastructure; +using Squidex.Infrastructure.Log; + +namespace Squidex.Pipeline +{ + public sealed class RequestLogProfilerSessionProvider : ILogProfilerSessionProvider + { + private const string ItemKey = "ProfilerSesison"; + private readonly IHttpContextAccessor httpContextAccessor; + + public RequestLogProfilerSessionProvider(IHttpContextAccessor httpContextAccessor) + { + this.httpContextAccessor = httpContextAccessor; + + Profile.Init(this); + } + + public ProfilerSession GetSession() + { + var context = httpContextAccessor?.HttpContext?.Items[ItemKey] as ProfilerSession; + + return context; + } + + public void Start(HttpContext httpContext, ProfilerSession session) + { + Guard.NotNull(httpContext, nameof(httpContext)); + + httpContext.Items[ItemKey] = session; + } + } +} diff --git a/src/Squidex/Program.cs b/src/Squidex/Program.cs index 9983b5694..f6b653bde 100644 --- a/src/Squidex/Program.cs +++ b/src/Squidex/Program.cs @@ -30,7 +30,7 @@ namespace Squidex { builder.AddConfiguration(hostingContext.Configuration.GetSection("logging")); builder.AddSemanticLog(); - builder.AddOrleansFilter(); + builder.AddFilter(); }) .ConfigureAppConfiguration((hostContext, builder) => { diff --git a/tests/Squidex.Infrastructure.Tests/UsageTracking/ThreadingUsageTrackerTests.cs b/tests/Squidex.Infrastructure.Tests/UsageTracking/ThreadingUsageTrackerTests.cs new file mode 100644 index 000000000..40a22b56a --- /dev/null +++ b/tests/Squidex.Infrastructure.Tests/UsageTracking/ThreadingUsageTrackerTests.cs @@ -0,0 +1,62 @@ +// ========================================================================== +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex UG (haftungsbeschraenkt) +// All rights reserved. Licensed under the MIT license. +// ========================================================================== + +using System; +using System.Threading.Tasks; +using FakeItEasy; +using Microsoft.Extensions.Caching.Memory; +using Microsoft.Extensions.Options; +using Xunit; + +namespace Squidex.Infrastructure.UsageTracking +{ + public sealed class ThreadingUsageTrackerTests + { + private readonly MemoryCache cache = new MemoryCache(Options.Create(new MemoryCacheOptions())); + private readonly IUsageTracker inner = A.Fake(); + private readonly IUsageTracker sut; + + public ThreadingUsageTrackerTests() + { + sut = new CachingUsageTracker(inner, cache); + } + + [Fact] + public async Task Should_forward_track_call() + { + await sut.TrackAsync("MyKey", 123, 456); + + A.CallTo(() => inner.TrackAsync("MyKey", 123, 456)) + .MustHaveHappened(); + } + + [Fact] + public async Task Should_forward_query_call() + { + await sut.QueryAsync("MyKey", DateTime.MaxValue, DateTime.MinValue); + + A.CallTo(() => inner.QueryAsync("MyKey", DateTime.MaxValue, DateTime.MinValue)) + .MustHaveHappened(); + } + + [Fact] + public async Task Should_cache_monthly_usage() + { + A.CallTo(() => inner.GetMonthlyCallsAsync("MyKey", DateTime.Today)) + .Returns(100); + + var result1 = await sut.GetMonthlyCallsAsync("MyKey", DateTime.Today); + var result2 = await sut.GetMonthlyCallsAsync("MyKey", DateTime.Today); + + Assert.Equal(100, result1); + Assert.Equal(100, result2); + + A.CallTo(() => inner.GetMonthlyCallsAsync("MyKey", DateTime.Today)) + .MustHaveHappened(Repeated.Exactly.Once); + } + } +}