From 79bccb61edabeec9566721d5fe9477a79df23a2e Mon Sep 17 00:00:00 2001 From: Sebastian Stehle Date: Sat, 1 Apr 2017 22:27:35 +0200 Subject: [PATCH] Semantic logging --- .../RedisInfrastructureErrors.cs | 19 -- .../RedisPubSub.cs | 27 +- .../RedisSubscription.cs | 17 +- .../Squidex.Infrastructure.Redis.csproj | 1 - .../CQRS/Commands/CommandContext.cs | 6 + .../CQRS/Commands/LogExceptionHandler.cs | 22 +- .../CQRS/Commands/LogExecutingHandler.cs | 16 +- .../CQRS/Events/Envelope_1.cs | 15 - .../CQRS/Events/EventReceiver.cs | 67 +++- .../DisposableObjectBase.cs | 13 +- .../InfrastructureErrors.cs | 25 -- .../Log/Adapter/SemanticLogLogger.cs | 102 ++++++ .../SemanticLogLoggerFactoryExtensions.cs | 22 ++ .../Log/Adapter/SemanticLogLoggerProvider.cs | 34 ++ .../Log/ApplicationInfoLogAppender.cs | 32 ++ .../Log/ConsoleLogChannel.cs | 28 ++ .../Log/ConstantsLogWriter.cs | 29 ++ .../Log/DebugLogChannel.cs | 20 ++ .../Log/IArrayWriter.cs | 26 ++ .../Log/ILogAppender.cs | 14 + src/Squidex.Infrastructure/Log/ILogChannel.cs | 14 + .../Log/IObjectWriter.cs | 27 ++ .../Log/ISemanticLog.cs | 19 ++ .../Log/Internal/AnsiLogConsole.cs | 39 +++ .../Log/Internal/ConsoleLogProcessor.cs | 73 +++++ .../Log/Internal/IConsole.cs | 14 + .../Log/Internal/LogMessageEntry.cs | 16 + .../Log/Internal/WindowsLogConsole.cs | 29 ++ .../Log/JsonLogWriter.cs | 185 +++++++++++ src/Squidex.Infrastructure/Log/SemanticLog.cs | 86 +++++ .../Log/SemanticLogExtensions.cs | 125 ++++++++ .../Log/SemanticLogLevel.cs | 19 ++ .../Log/TimestampLogAppender.cs | 34 ++ .../Contents/Visitors/FindExtensions.cs | 4 + .../Config/Domain/InfrastructureModule.cs | 37 +++ .../UI/Account/AccountController.cs | 19 +- src/Squidex/Pipeline/WebpackMiddleware.cs | 22 +- src/Squidex/Startup.cs | 5 +- src/Squidex/appsettings.json | 3 + .../CQRS/Commands/LogExceptionHandlerTests.cs | 27 +- .../CQRS/Commands/LogExecutingHandlerTests.cs | 21 +- .../CQRS/Events/EventReceiverTests.cs | 43 ++- .../Log/JsonLogWriterTests.cs | 163 ++++++++++ .../Log/SemanticLogTests.cs | 300 ++++++++++++++++++ 44 files changed, 1664 insertions(+), 195 deletions(-) delete mode 100644 src/Squidex.Infrastructure.Redis/RedisInfrastructureErrors.cs delete mode 100644 src/Squidex.Infrastructure/InfrastructureErrors.cs create mode 100644 src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs create mode 100644 src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerFactoryExtensions.cs create mode 100644 src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerProvider.cs create mode 100644 src/Squidex.Infrastructure/Log/ApplicationInfoLogAppender.cs create mode 100644 src/Squidex.Infrastructure/Log/ConsoleLogChannel.cs create mode 100644 src/Squidex.Infrastructure/Log/ConstantsLogWriter.cs create mode 100644 src/Squidex.Infrastructure/Log/DebugLogChannel.cs create mode 100644 src/Squidex.Infrastructure/Log/IArrayWriter.cs create mode 100644 src/Squidex.Infrastructure/Log/ILogAppender.cs create mode 100644 src/Squidex.Infrastructure/Log/ILogChannel.cs create mode 100644 src/Squidex.Infrastructure/Log/IObjectWriter.cs create mode 100644 src/Squidex.Infrastructure/Log/ISemanticLog.cs create mode 100644 src/Squidex.Infrastructure/Log/Internal/AnsiLogConsole.cs create mode 100644 src/Squidex.Infrastructure/Log/Internal/ConsoleLogProcessor.cs create mode 100644 src/Squidex.Infrastructure/Log/Internal/IConsole.cs create mode 100644 src/Squidex.Infrastructure/Log/Internal/LogMessageEntry.cs create mode 100644 src/Squidex.Infrastructure/Log/Internal/WindowsLogConsole.cs create mode 100644 src/Squidex.Infrastructure/Log/JsonLogWriter.cs create mode 100644 src/Squidex.Infrastructure/Log/SemanticLog.cs create mode 100644 src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs create mode 100644 src/Squidex.Infrastructure/Log/SemanticLogLevel.cs create mode 100644 src/Squidex.Infrastructure/Log/TimestampLogAppender.cs create mode 100644 tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs create mode 100644 tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs diff --git a/src/Squidex.Infrastructure.Redis/RedisInfrastructureErrors.cs b/src/Squidex.Infrastructure.Redis/RedisInfrastructureErrors.cs deleted file mode 100644 index 1fca8ec32..000000000 --- a/src/Squidex.Infrastructure.Redis/RedisInfrastructureErrors.cs +++ /dev/null @@ -1,19 +0,0 @@ -// ========================================================================== -// RedisInfrastructureErrors.cs -// Squidex Headless CMS -// ========================================================================== -// Copyright (c) Squidex Group -// All rights reserved. -// ========================================================================== - -using Microsoft.Extensions.Logging; - -namespace Squidex.Infrastructure.Redis -{ - public static class RedisInfrastructureErrors - { - public static readonly EventId InvalidatingReceivedFailed = new EventId(50001, "InvalidingReceivedFailed"); - - public static readonly EventId InvalidatingPublishedFailed = new EventId(50002, "InvalidatingPublishedFailed"); - } -} diff --git a/src/Squidex.Infrastructure.Redis/RedisPubSub.cs b/src/Squidex.Infrastructure.Redis/RedisPubSub.cs index dcf893bb8..de71cb843 100644 --- a/src/Squidex.Infrastructure.Redis/RedisPubSub.cs +++ b/src/Squidex.Infrastructure.Redis/RedisPubSub.cs @@ -8,7 +8,7 @@ using System; using System.Collections.Concurrent; -using Microsoft.Extensions.Logging; +using Squidex.Infrastructure.Log; using StackExchange.Redis; namespace Squidex.Infrastructure.Redis @@ -16,31 +16,30 @@ namespace Squidex.Infrastructure.Redis public class RedisPubSub : IPubSub, IExternalSystem { private readonly ConcurrentDictionary subscriptions = new ConcurrentDictionary(); - private readonly IConnectionMultiplexer redis; - private readonly ILogger logger; - private readonly ISubscriber subscriber; + private readonly IConnectionMultiplexer redisClient; + private readonly ISemanticLog log; + private readonly ISubscriber redisSubscriber; - public RedisPubSub(IConnectionMultiplexer redis, ILogger logger) + public RedisPubSub(IConnectionMultiplexer redis, ISemanticLog log) { Guard.NotNull(redis, nameof(redis)); - Guard.NotNull(logger, nameof(logger)); + Guard.NotNull(log, nameof(log)); - this.redis = redis; + this.log = log; - this.logger = logger; - - subscriber = redis.GetSubscriber(); + redisClient = redis; + redisSubscriber = redis.GetSubscriber(); } public void Connect() { try { - redis.GetStatus(); + redisClient.GetStatus(); } catch (Exception ex) { - throw new ConfigurationException($"Redis connection failed to connect to database {redis.Configuration}", ex); + throw new ConfigurationException($"Redis connection failed to connect to database {redisClient.Configuration}", ex); } } @@ -48,14 +47,14 @@ namespace Squidex.Infrastructure.Redis { Guard.NotNullOrEmpty(channelName, nameof(channelName)); - subscriptions.GetOrAdd(channelName, c => new RedisSubscription(subscriber, c, logger)).Publish(token, notifySelf); + subscriptions.GetOrAdd(channelName, c => new RedisSubscription(redisSubscriber, c, log)).Publish(token, notifySelf); } public IDisposable Subscribe(string channelName, Action handler) { Guard.NotNullOrEmpty(channelName, nameof(channelName)); - return subscriptions.GetOrAdd(channelName, c => new RedisSubscription(subscriber, c, logger)).Subscribe(handler); + return subscriptions.GetOrAdd(channelName, c => new RedisSubscription(redisSubscriber, c, log)).Subscribe(handler); } } } diff --git a/src/Squidex.Infrastructure.Redis/RedisSubscription.cs b/src/Squidex.Infrastructure.Redis/RedisSubscription.cs index ac3140fce..a7b628dd8 100644 --- a/src/Squidex.Infrastructure.Redis/RedisSubscription.cs +++ b/src/Squidex.Infrastructure.Redis/RedisSubscription.cs @@ -9,7 +9,7 @@ using System; using System.Linq; using System.Reactive.Subjects; -using Microsoft.Extensions.Logging; +using Squidex.Infrastructure.Log; using StackExchange.Redis; // ReSharper disable InvertIf @@ -22,11 +22,11 @@ namespace Squidex.Infrastructure.Redis private readonly Subject subject = new Subject(); private readonly ISubscriber subscriber; private readonly string channelName; - private readonly ILogger logger; + private readonly ISemanticLog log; - public RedisSubscription(ISubscriber subscriber, string channelName, ILogger logger) + public RedisSubscription(ISubscriber subscriber, string channelName, ISemanticLog log) { - this.logger = logger; + this.log = log; this.subscriber = subscriber; this.subscriber.Subscribe(channelName, (channel, value) => HandleInvalidation(value)); @@ -44,7 +44,10 @@ namespace Squidex.Infrastructure.Redis } catch (Exception ex) { - logger.LogError(RedisInfrastructureErrors.InvalidatingReceivedFailed, ex, "Failed to send invalidation message {0}", token); + log.LogError(ex, w => w + .WriteProperty("action", "PublishRedisMessage") + .WriteProperty("state", "Failed") + .WriteProperty("token", token)); } } @@ -78,7 +81,9 @@ namespace Squidex.Infrastructure.Redis } catch (Exception ex) { - logger.LogError(RedisInfrastructureErrors.InvalidatingReceivedFailed, ex, "Failed to receive invalidation message."); + log.LogError(ex, w => w + .WriteProperty("action", "ReceiveRedisMessage") + .WriteProperty("state", "Failed")); } } diff --git a/src/Squidex.Infrastructure.Redis/Squidex.Infrastructure.Redis.csproj b/src/Squidex.Infrastructure.Redis/Squidex.Infrastructure.Redis.csproj index 98a461896..5e5b44588 100644 --- a/src/Squidex.Infrastructure.Redis/Squidex.Infrastructure.Redis.csproj +++ b/src/Squidex.Infrastructure.Redis/Squidex.Infrastructure.Redis.csproj @@ -10,7 +10,6 @@ - diff --git a/src/Squidex.Infrastructure/CQRS/Commands/CommandContext.cs b/src/Squidex.Infrastructure/CQRS/Commands/CommandContext.cs index 31f76e399..113f85317 100644 --- a/src/Squidex.Infrastructure/CQRS/Commands/CommandContext.cs +++ b/src/Squidex.Infrastructure/CQRS/Commands/CommandContext.cs @@ -13,6 +13,7 @@ namespace Squidex.Infrastructure.CQRS.Commands public sealed class CommandContext { private readonly ICommand command; + private readonly Guid contextId = Guid.NewGuid(); private Exception exception; private Tuple result; @@ -41,6 +42,11 @@ namespace Squidex.Infrastructure.CQRS.Commands get { return exception; } } + public Guid ContextId + { + get { return contextId; } + } + public CommandContext(ICommand command) { Guard.NotNull(command, nameof(command)); diff --git a/src/Squidex.Infrastructure/CQRS/Commands/LogExceptionHandler.cs b/src/Squidex.Infrastructure/CQRS/Commands/LogExceptionHandler.cs index 0e31d7548..80efac561 100644 --- a/src/Squidex.Infrastructure/CQRS/Commands/LogExceptionHandler.cs +++ b/src/Squidex.Infrastructure/CQRS/Commands/LogExceptionHandler.cs @@ -7,7 +7,7 @@ // ========================================================================== using System.Threading.Tasks; -using Microsoft.Extensions.Logging; +using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Tasks; // ReSharper disable InvertIf @@ -16,11 +16,13 @@ namespace Squidex.Infrastructure.CQRS.Commands { public sealed class LogExceptionHandler : ICommandHandler { - private readonly ILogger logger; + private readonly ISemanticLog log; - public LogExceptionHandler(ILogger logger) + public LogExceptionHandler(ISemanticLog log) { - this.logger = logger; + Guard.NotNull(log, nameof(log)); + + this.log = log; } public Task HandleAsync(CommandContext context) @@ -29,12 +31,20 @@ namespace Squidex.Infrastructure.CQRS.Commands if (exception != null) { - logger.LogError(InfrastructureErrors.CommandFailed, exception, "Handling {0} command failed", context.Command); + log.LogError(exception, w => w + .WriteProperty("action", "HandleCommand.") + .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("state", "Failed") + .WriteProperty("commandType", context.Command.GetType().Name)); } if (!context.IsHandled) { - logger.LogCritical(InfrastructureErrors.CommandUnknown, exception, "Unknown command {0}", context.Command); + log.LogFatal(exception, w => w + .WriteProperty("action", "HandleCommand.") + .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("state", "Unhandled") + .WriteProperty("commandType", context.Command.GetType().Name)); } return TaskHelper.False; diff --git a/src/Squidex.Infrastructure/CQRS/Commands/LogExecutingHandler.cs b/src/Squidex.Infrastructure/CQRS/Commands/LogExecutingHandler.cs index d95a02cd6..646c97262 100644 --- a/src/Squidex.Infrastructure/CQRS/Commands/LogExecutingHandler.cs +++ b/src/Squidex.Infrastructure/CQRS/Commands/LogExecutingHandler.cs @@ -7,23 +7,29 @@ // ========================================================================== using System.Threading.Tasks; -using Microsoft.Extensions.Logging; +using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Tasks; namespace Squidex.Infrastructure.CQRS.Commands { public sealed class LogExecutingHandler : ICommandHandler { - private readonly ILogger logger; + private readonly ISemanticLog log; - public LogExecutingHandler(ILogger logger) + public LogExecutingHandler(ISemanticLog log) { - this.logger = logger; + Guard.NotNull(log, nameof(log)); + + this.log = log; } public Task HandleAsync(CommandContext context) { - logger.LogInformation("Handling {0} command", context.Command); + log.LogInformation(w => w + .WriteProperty("action", "HandleCommand.") + .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("state", "Started") + .WriteProperty("commandType", context.Command.GetType().Name)); return TaskHelper.False; } diff --git a/src/Squidex.Infrastructure/CQRS/Events/Envelope_1.cs b/src/Squidex.Infrastructure/CQRS/Events/Envelope_1.cs index e2bf2aa45..502917536 100644 --- a/src/Squidex.Infrastructure/CQRS/Events/Envelope_1.cs +++ b/src/Squidex.Infrastructure/CQRS/Events/Envelope_1.cs @@ -6,9 +6,6 @@ // All rights reserved. // ========================================================================== -using System; -using NodaTime; - namespace Squidex.Infrastructure.CQRS.Events { public class Envelope where TPayload : class @@ -45,18 +42,6 @@ namespace Squidex.Infrastructure.CQRS.Events this.headers = headers; } - public static Envelope Create(TPayload payload) - { - var eventId = Guid.NewGuid(); - - var envelope = - new Envelope(payload) - .SetEventId(eventId) - .SetTimestamp(SystemClock.Instance.GetCurrentInstant()); - - return envelope; - } - public Envelope To() where TOther : class { return new Envelope(payload as TOther, headers.Clone()); diff --git a/src/Squidex.Infrastructure/CQRS/Events/EventReceiver.cs b/src/Squidex.Infrastructure/CQRS/Events/EventReceiver.cs index c0660a18e..5bf6f0768 100644 --- a/src/Squidex.Infrastructure/CQRS/Events/EventReceiver.cs +++ b/src/Squidex.Infrastructure/CQRS/Events/EventReceiver.cs @@ -9,7 +9,7 @@ using System; using System.Reactive.Linq; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; +using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Timers; // ReSharper disable MethodSupportsCancellation @@ -24,7 +24,7 @@ namespace Squidex.Infrastructure.CQRS.Events private readonly IEventStore eventStore; private readonly IEventNotifier eventNotifier; private readonly IEventConsumerInfoRepository eventConsumerInfoRepository; - private readonly ILogger logger; + private readonly ISemanticLog log; private CompletionTimer timer; public EventReceiver( @@ -32,15 +32,15 @@ namespace Squidex.Infrastructure.CQRS.Events IEventStore eventStore, IEventNotifier eventNotifier, IEventConsumerInfoRepository eventConsumerInfoRepository, - ILogger logger) + ISemanticLog log) { - Guard.NotNull(logger, nameof(logger)); + Guard.NotNull(log, nameof(log)); Guard.NotNull(formatter, nameof(formatter)); Guard.NotNull(eventStore, nameof(eventStore)); Guard.NotNull(eventNotifier, nameof(eventNotifier)); Guard.NotNull(eventConsumerInfoRepository, nameof(eventConsumerInfoRepository)); - this.logger = logger; + this.log = log; this.formatter = formatter; this.eventStore = eventStore; this.eventNotifier = eventNotifier; @@ -57,7 +57,9 @@ namespace Squidex.Infrastructure.CQRS.Events } catch (Exception ex) { - logger.LogCritical(InfrastructureErrors.EventHandlingFailed, ex, "Event stream {0} has been aborted"); + log.LogWarning(ex, w => w + .WriteProperty("action", "DisposeEventReceiver") + .WriteProperty("state", "Failed")); } } } @@ -115,7 +117,7 @@ namespace Squidex.Infrastructure.CQRS.Events } catch (Exception ex) { - logger.LogError(InfrastructureErrors.EventHandlingFailed, ex, "Failed to handle events"); + log.LogFatal(ex, w => w.WriteProperty("action", "EventHandlingFailed")); await eventConsumerInfoRepository.StopAsync(consumerName, ex.ToString()); } @@ -134,18 +136,31 @@ namespace Squidex.Infrastructure.CQRS.Events private async Task ResetAsync(IEventConsumer eventConsumer, string consumerName) { + var actionId = Guid.NewGuid().ToString(); try { - logger.LogDebug("[{0}]: Reset started", eventConsumer); + log.LogInformation(w => w + .WriteProperty("action", "EventConsumerReset") + .WriteProperty("actionId", actionId) + .WriteProperty("state", "Started") + .WriteProperty("eventConsumer", eventConsumer.GetType().Name)); await eventConsumer.ClearAsync(); await eventConsumerInfoRepository.SetLastHandledEventNumberAsync(consumerName, -1); - logger.LogDebug("[{0}]: Reset completed", eventConsumer); + log.LogInformation(w => w + .WriteProperty("action", "EventConsumerReset") + .WriteProperty("actionId", actionId) + .WriteProperty("state", "Completed") + .WriteProperty("eventConsumer", eventConsumer.GetType().Name)); } catch (Exception ex) { - logger.LogError(InfrastructureErrors.EventResetFailed, ex, "[{0}]: Reset failed", eventConsumer); + log.LogFatal(ex, w => w + .WriteProperty("action", "EventConsumerReset") + .WriteProperty("actionId", actionId) + .WriteProperty("state", "Completed") + .WriteProperty("eventConsumer", eventConsumer.GetType().Name)); throw; } @@ -153,17 +168,37 @@ namespace Squidex.Infrastructure.CQRS.Events private async Task DispatchConsumer(Envelope @event, IEventConsumer eventConsumer) { + var eventId = @event.Headers.EventId().ToString(); + var eventType = @event.Payload.GetType().Name; try { - logger.LogDebug("[{0}]: Handling event {1} ({2})", eventConsumer, @event.Payload, @event.Headers.EventId()); + log.LogInformation(w => w + .WriteProperty("action", "HandleEvent") + .WriteProperty("actionId", eventId) + .WriteProperty("state", "Started") + .WriteProperty("eventId", eventId) + .WriteProperty("eventType", eventType) + .WriteProperty("eventConsumer", eventConsumer.GetType().Name)); await eventConsumer.On(@event); - logger.LogDebug("[{0}]: Handled event {1} ({2})", eventConsumer, @event.Payload, @event.Headers.EventId()); + log.LogInformation(w => w + .WriteProperty("action", "HandleEvent") + .WriteProperty("actionId", eventId) + .WriteProperty("state", "Completed") + .WriteProperty("eventId", eventId) + .WriteProperty("eventType", eventType) + .WriteProperty("eventConsumer", eventConsumer.GetType().Name)); } catch (Exception ex) { - logger.LogError(InfrastructureErrors.EventHandlingFailed, ex, "[{0}]: Failed to handle event {1} ({2})", eventConsumer, @event.Payload, @event.Headers.EventId()); + log.LogError(ex, w => w + .WriteProperty("action", "HandleEvent") + .WriteProperty("actionId", eventId) + .WriteProperty("state", "Started") + .WriteProperty("eventId", eventId) + .WriteProperty("eventType", eventType) + .WriteProperty("eventConsumer", eventConsumer.GetType().Name)); throw; } @@ -182,7 +217,11 @@ namespace Squidex.Infrastructure.CQRS.Events } catch (Exception ex) { - logger.LogError(InfrastructureErrors.EventDeserializationFailed, ex, "Failed to parse event {0}", storedEvent.Data.EventId); + log.LogFatal(ex, w => w + .WriteProperty("action", "ParseEvent") + .WriteProperty("state", "Failed") + .WriteProperty("eventId", storedEvent.Data.EventId.ToString()) + .WriteProperty("eventNumber", storedEvent.EventNumber)); throw; } diff --git a/src/Squidex.Infrastructure/DisposableObjectBase.cs b/src/Squidex.Infrastructure/DisposableObjectBase.cs index a8ead1cbd..f79a12c8f 100644 --- a/src/Squidex.Infrastructure/DisposableObjectBase.cs +++ b/src/Squidex.Infrastructure/DisposableObjectBase.cs @@ -36,20 +36,13 @@ namespace Squidex.Infrastructure return; } - if (disposing) + lock (disposeLock) { - lock (disposeLock) + if (!isDisposed) { - if (!isDisposed) - { - DisposeObject(true); - } + DisposeObject(disposing); } } - else - { - DisposeObject(false); - } isDisposed = true; } diff --git a/src/Squidex.Infrastructure/InfrastructureErrors.cs b/src/Squidex.Infrastructure/InfrastructureErrors.cs deleted file mode 100644 index 0d006dd0b..000000000 --- a/src/Squidex.Infrastructure/InfrastructureErrors.cs +++ /dev/null @@ -1,25 +0,0 @@ -// ========================================================================== -// InfrastructureErrors.cs -// Squidex Headless CMS -// ========================================================================== -// Copyright (c) Squidex Group -// All rights reserved. -// ========================================================================== - -using Microsoft.Extensions.Logging; - -namespace Squidex.Infrastructure -{ - public class InfrastructureErrors - { - public static readonly EventId CommandUnknown = new EventId(20000, "CommandUnknown"); - - public static readonly EventId CommandFailed = new EventId(20001, "CommandFailed"); - - public static readonly EventId EventResetFailed = new EventId(10000, "EventResetFailed"); - - public static readonly EventId EventHandlingFailed = new EventId(10001, "EventHandlingFailed"); - - public static readonly EventId EventDeserializationFailed = new EventId(10002, "EventDeserializationFailed"); - } -} diff --git a/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs new file mode 100644 index 000000000..812b513d9 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs @@ -0,0 +1,102 @@ +// ========================================================================== +// SemanticLogLogger.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using Microsoft.Extensions.Logging; + +// ReSharper disable SwitchStatementMissingSomeCases + +namespace Squidex.Infrastructure.Log.Adapter +{ + internal sealed class SemanticLogLogger : ILogger + { + private readonly ISemanticLog semanticLog; + + public SemanticLogLogger(ISemanticLog semanticLog) + { + this.semanticLog = semanticLog; + } + + public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) + { + SemanticLogLevel semanticLogLevel; + + switch (logLevel) + { + case LogLevel.Trace: + semanticLogLevel = SemanticLogLevel.Trace; + break; + case LogLevel.Debug: + semanticLogLevel = SemanticLogLevel.Debug; + break; + case LogLevel.Information: + semanticLogLevel = SemanticLogLevel.Information; + break; + case LogLevel.Warning: + semanticLogLevel = SemanticLogLevel.Warning; + break; + case LogLevel.Error: + semanticLogLevel = SemanticLogLevel.Error; + break; + case LogLevel.Critical: + semanticLogLevel = SemanticLogLevel.Fatal; + break; + default: + semanticLogLevel = SemanticLogLevel.Debug; + break; + } + + semanticLog.Log(semanticLogLevel, writer => + { + var message = formatter(state, exception); + + if (!string.IsNullOrWhiteSpace(message)) + { + writer.WriteProperty(nameof(message), message); + } + + if (eventId.Id > 0) + { + writer.WriteObject(nameof(eventId), eventIdWriter => + { + eventIdWriter.WriteProperty("id", eventId.Id); + + if (!string.IsNullOrWhiteSpace(eventId.Name)) + { + eventIdWriter.WriteProperty("name", eventId.Name); + } + }); + } + + if (exception != null) + { + writer.WriteException(exception); + } + }); + } + + public bool IsEnabled(LogLevel logLevel) + { + return true; + } + + public IDisposable BeginScope(TState state) + { + return NoopDisposable.Instance; + } + + private class NoopDisposable : IDisposable + { + public static readonly NoopDisposable Instance = new NoopDisposable(); + + public void Dispose() + { + } + } + } +} diff --git a/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerFactoryExtensions.cs b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerFactoryExtensions.cs new file mode 100644 index 000000000..662da7078 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerFactoryExtensions.cs @@ -0,0 +1,22 @@ +// ========================================================================== +// SemanticLogLoggerFactoryExtensions.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using Microsoft.Extensions.Logging; + +namespace Squidex.Infrastructure.Log.Adapter +{ + public static class SemanticLogLoggerFactoryExtensions + { + public static ILoggerFactory AddSemanticLog(this ILoggerFactory factory, ISemanticLog semanticLog) + { + factory.AddProvider(new SemanticLogLoggerProvider(semanticLog)); + + return factory; + } + } +} diff --git a/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerProvider.cs b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerProvider.cs new file mode 100644 index 000000000..3bd84a2b1 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLoggerProvider.cs @@ -0,0 +1,34 @@ +// ========================================================================== +// SemanticLogLoggerProvider.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using Microsoft.Extensions.Logging; + +namespace Squidex.Infrastructure.Log.Adapter +{ + public class SemanticLogLoggerProvider : ILoggerProvider + { + private readonly ISemanticLog semanticLog; + + public SemanticLogLoggerProvider(ISemanticLog semanticLog) + { + this.semanticLog = semanticLog; + } + + public ILogger CreateLogger(string categoryName) + { + return new SemanticLogLogger(semanticLog.CreateScope(writer => + { + writer.WriteProperty("category", categoryName); + })); + } + + public void Dispose() + { + } + } +} diff --git a/src/Squidex.Infrastructure/Log/ApplicationInfoLogAppender.cs b/src/Squidex.Infrastructure/Log/ApplicationInfoLogAppender.cs new file mode 100644 index 000000000..3926495b2 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ApplicationInfoLogAppender.cs @@ -0,0 +1,32 @@ +// ========================================================================== +// ApplicationInfoLogAppender.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System.Reflection; + +namespace Squidex.Infrastructure.Log +{ + public sealed class ApplicationInfoLogAppender : ILogAppender + { + private readonly string applicationName; + private readonly string applicationVersion; + + public ApplicationInfoLogAppender(Assembly assembly) + { + Guard.NotNull(assembly, nameof(assembly)); + + applicationName = assembly.GetName().Name; + applicationVersion = assembly.GetName().Version.ToString(); + } + + public void Append(IObjectWriter writer) + { + writer.WriteProperty("applicationName", applicationName); + writer.WriteProperty("applicationVersion", applicationVersion); + } + } +} diff --git a/src/Squidex.Infrastructure/Log/ConsoleLogChannel.cs b/src/Squidex.Infrastructure/Log/ConsoleLogChannel.cs new file mode 100644 index 000000000..c9c3b3d81 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ConsoleLogChannel.cs @@ -0,0 +1,28 @@ +// ========================================================================== +// ConsoleLogChannel.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using Squidex.Infrastructure.Log.Internal; + +namespace Squidex.Infrastructure.Log +{ + public sealed class ConsoleLogChannel : ILogChannel, IDisposable + { + private readonly ConsoleLogProcessor processor = new ConsoleLogProcessor(); + + public void Dispose() + { + processor.Dispose(); + } + + public void Log(SemanticLogLevel logLevel, string message) + { + processor.EnqueueMessage(new LogMessageEntry { Message = message, Level = logLevel }); + } + } +} diff --git a/src/Squidex.Infrastructure/Log/ConstantsLogWriter.cs b/src/Squidex.Infrastructure/Log/ConstantsLogWriter.cs new file mode 100644 index 000000000..4af82cbed --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ConstantsLogWriter.cs @@ -0,0 +1,29 @@ +// ========================================================================== +// ConstantsLogWriter.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; + +namespace Squidex.Infrastructure.Log +{ + public sealed class ConstantsLogWriter : ILogAppender + { + private readonly Action objectWriter; + + public ConstantsLogWriter(Action objectWriter) + { + Guard.NotNull(objectWriter, nameof(objectWriter)); + + this.objectWriter = objectWriter; + } + + public void Append(IObjectWriter writer) + { + objectWriter(writer); + } + } +} diff --git a/src/Squidex.Infrastructure/Log/DebugLogChannel.cs b/src/Squidex.Infrastructure/Log/DebugLogChannel.cs new file mode 100644 index 000000000..7816b83eb --- /dev/null +++ b/src/Squidex.Infrastructure/Log/DebugLogChannel.cs @@ -0,0 +1,20 @@ +// ========================================================================== +// DebugLogChannel.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System.Diagnostics; + +namespace Squidex.Infrastructure.Log +{ + public sealed class DebugLogChannel : ILogChannel + { + public void Log(SemanticLogLevel logLevel, string message) + { + Debug.WriteLine(message); + } + } +} diff --git a/src/Squidex.Infrastructure/Log/IArrayWriter.cs b/src/Squidex.Infrastructure/Log/IArrayWriter.cs new file mode 100644 index 000000000..127fcb157 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/IArrayWriter.cs @@ -0,0 +1,26 @@ +// ========================================================================== +// IArrayWriter.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; + +namespace Squidex.Infrastructure.Log +{ + public interface IArrayWriter + { + IArrayWriter WriteValue(string value); + IArrayWriter WriteValue(double value); + IArrayWriter WriteValue(long value); + IArrayWriter WriteValue(bool value); + + IArrayWriter WriteValue(TimeSpan value); + IArrayWriter WriteValue(DateTime value); + IArrayWriter WriteValue(DateTimeOffset value); + + IArrayWriter WriteObject(string property, Action objectWriter); + } +} \ No newline at end of file diff --git a/src/Squidex.Infrastructure/Log/ILogAppender.cs b/src/Squidex.Infrastructure/Log/ILogAppender.cs new file mode 100644 index 000000000..596c6b8d6 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ILogAppender.cs @@ -0,0 +1,14 @@ +// ========================================================================== +// ILogAppender.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== +namespace Squidex.Infrastructure.Log +{ + public interface ILogAppender + { + void Append(IObjectWriter writer); + } +} diff --git a/src/Squidex.Infrastructure/Log/ILogChannel.cs b/src/Squidex.Infrastructure/Log/ILogChannel.cs new file mode 100644 index 000000000..20ebee481 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ILogChannel.cs @@ -0,0 +1,14 @@ +// ========================================================================== +// ILogChannel.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== +namespace Squidex.Infrastructure.Log +{ + public interface ILogChannel + { + void Log(SemanticLogLevel logLevel, string message); + } +} \ No newline at end of file diff --git a/src/Squidex.Infrastructure/Log/IObjectWriter.cs b/src/Squidex.Infrastructure/Log/IObjectWriter.cs new file mode 100644 index 000000000..db331826b --- /dev/null +++ b/src/Squidex.Infrastructure/Log/IObjectWriter.cs @@ -0,0 +1,27 @@ +// ========================================================================== +// IObjectWriter.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; + +namespace Squidex.Infrastructure.Log +{ + public interface IObjectWriter + { + IObjectWriter WriteProperty(string property, string value); + IObjectWriter WriteProperty(string property, double value); + IObjectWriter WriteProperty(string property, long value); + IObjectWriter WriteProperty(string property, bool value); + + IObjectWriter WriteProperty(string property, TimeSpan value); + IObjectWriter WriteProperty(string property, DateTime value); + IObjectWriter WriteProperty(string property, DateTimeOffset value); + + IObjectWriter WriteObject(string property, Action objectWriter); + IObjectWriter WriteArray(string property, Action arrayWriter); + } +} diff --git a/src/Squidex.Infrastructure/Log/ISemanticLog.cs b/src/Squidex.Infrastructure/Log/ISemanticLog.cs new file mode 100644 index 000000000..1fb09f70d --- /dev/null +++ b/src/Squidex.Infrastructure/Log/ISemanticLog.cs @@ -0,0 +1,19 @@ +// ========================================================================== +// ISemanticLog.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; + +namespace Squidex.Infrastructure.Log +{ + public interface ISemanticLog + { + void Log(SemanticLogLevel logLevel, Action action); + + ISemanticLog CreateScope(Action objectWriter); + } +} diff --git a/src/Squidex.Infrastructure/Log/Internal/AnsiLogConsole.cs b/src/Squidex.Infrastructure/Log/Internal/AnsiLogConsole.cs new file mode 100644 index 000000000..41666b8cf --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Internal/AnsiLogConsole.cs @@ -0,0 +1,39 @@ +// ========================================================================== +// AnsiLogConsole.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using System.Text; + +// ReSharper disable SwitchStatementMissingSomeCases + +namespace Squidex.Infrastructure.Log.Internal +{ + public class AnsiLogConsole : IConsole + { + private readonly StringBuilder outputBuilder = new StringBuilder(); + + public void WriteLine(SemanticLogLevel level, string message) + { + if (level >= SemanticLogLevel.Error) + { + outputBuilder.Append("\x1B[1m\x1B[31m"); + outputBuilder.Append(message); + outputBuilder.Append("\x1B[39m\x1B[22m"); + outputBuilder.AppendLine(); + + Console.Error.Write(outputBuilder.ToString()); + } + else + { + Console.Out.Write(outputBuilder.ToString()); + } + + outputBuilder.Clear(); + } + } +} diff --git a/src/Squidex.Infrastructure/Log/Internal/ConsoleLogProcessor.cs b/src/Squidex.Infrastructure/Log/Internal/ConsoleLogProcessor.cs new file mode 100644 index 000000000..f48a74f79 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Internal/ConsoleLogProcessor.cs @@ -0,0 +1,73 @@ +// ========================================================================== +// ConsoleLogProcessor.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using System.Collections.Concurrent; +using System.Runtime.InteropServices; +using System.Threading.Tasks; + +namespace Squidex.Infrastructure.Log.Internal +{ + public class ConsoleLogProcessor : IDisposable + { + private readonly IConsole console; + private const int MaxQueuedMessages = 1024; + private readonly BlockingCollection messageQueue = new BlockingCollection(MaxQueuedMessages); + private readonly Task outputTask; + + public ConsoleLogProcessor() + { + if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) + { + console = new WindowsLogConsole(); + } + else + { + console = new AnsiLogConsole(); + } + + outputTask = Task.Factory.StartNew(ProcessLogQueue, this, TaskCreationOptions.LongRunning); + } + + public void EnqueueMessage(LogMessageEntry message) + { + messageQueue.Add(message); + } + + private void ProcessLogQueue() + { + foreach (var entry in messageQueue.GetConsumingEnumerable()) + { + console.WriteLine(entry.Level, entry.Message); + } + } + + private static void ProcessLogQueue(object state) + { + var processor = (ConsoleLogProcessor)state; + + processor.ProcessLogQueue(); + } + + public void Dispose() + { + messageQueue.CompleteAdding(); + + try + { + outputTask.Wait(1500); + } + catch (TaskCanceledException) + { + } + catch (AggregateException ex) when (ex.InnerExceptions.Count == 1 && ex.InnerExceptions[0] is TaskCanceledException) + { + } + } + } +} diff --git a/src/Squidex.Infrastructure/Log/Internal/IConsole.cs b/src/Squidex.Infrastructure/Log/Internal/IConsole.cs new file mode 100644 index 000000000..801a61e9b --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Internal/IConsole.cs @@ -0,0 +1,14 @@ +// ========================================================================== +// IConsole.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== +namespace Squidex.Infrastructure.Log.Internal +{ + public interface IConsole + { + void WriteLine(SemanticLogLevel level, string message); + } +} diff --git a/src/Squidex.Infrastructure/Log/Internal/LogMessageEntry.cs b/src/Squidex.Infrastructure/Log/Internal/LogMessageEntry.cs new file mode 100644 index 000000000..5843bcd7c --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Internal/LogMessageEntry.cs @@ -0,0 +1,16 @@ +// ========================================================================== +// LogMessageEntry.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== +namespace Squidex.Infrastructure.Log.Internal +{ + public struct LogMessageEntry + { + public SemanticLogLevel Level; + + public string Message; + } +} diff --git a/src/Squidex.Infrastructure/Log/Internal/WindowsLogConsole.cs b/src/Squidex.Infrastructure/Log/Internal/WindowsLogConsole.cs new file mode 100644 index 000000000..b471cc5a5 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/Internal/WindowsLogConsole.cs @@ -0,0 +1,29 @@ +// ========================================================================== +// WindowsLogConsole.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; + +namespace Squidex.Infrastructure.Log.Internal +{ + public class WindowsLogConsole : IConsole + { + public void WriteLine(SemanticLogLevel level, string message) + { + if (level >= SemanticLogLevel.Error) + { + Console.ForegroundColor = ConsoleColor.Red; + Console.Error.WriteLine(message); + Console.ResetColor(); + } + else + { + Console.Out.WriteLine(message); + } + } + } +} diff --git a/src/Squidex.Infrastructure/Log/JsonLogWriter.cs b/src/Squidex.Infrastructure/Log/JsonLogWriter.cs new file mode 100644 index 000000000..b35f9d830 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/JsonLogWriter.cs @@ -0,0 +1,185 @@ +// ========================================================================== +// JsonLogWriter.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using System.Globalization; +using System.IO; +using Newtonsoft.Json; + +namespace Squidex.Infrastructure.Log +{ + public sealed class JsonLogWriter : IObjectWriter, IArrayWriter + { + private readonly bool extraLine; + private readonly StringWriter textWriter = new StringWriter(); + private readonly JsonWriter jsonWriter; + + public JsonLogWriter(Formatting formatting = Formatting.None, bool extraLine = false) + { + this.extraLine = extraLine; + + jsonWriter = new JsonTextWriter(textWriter) { Formatting = formatting }; + jsonWriter.WriteStartObject(); + } + + IArrayWriter IArrayWriter.WriteValue(string value) + { + jsonWriter.WriteValue(value); + + return this; + } + + IArrayWriter IArrayWriter.WriteValue(double value) + { + jsonWriter.WriteValue(value); + + return this; + } + + IArrayWriter IArrayWriter.WriteValue(long value) + { + jsonWriter.WriteValue(value); + + return this; + } + + IArrayWriter IArrayWriter.WriteValue(bool value) + { + jsonWriter.WriteValue(value); + + return this; + } + + IArrayWriter IArrayWriter.WriteValue(DateTime value) + { + jsonWriter.WriteValue(value.ToString("o", CultureInfo.InvariantCulture)); + + return this; + } + + IArrayWriter IArrayWriter.WriteValue(DateTimeOffset value) + { + jsonWriter.WriteValue(value.ToString("o", CultureInfo.InvariantCulture)); + + return this; + } + + IArrayWriter IArrayWriter.WriteValue(TimeSpan value) + { + jsonWriter.WriteValue(value); + + return this; + } + + IObjectWriter IObjectWriter.WriteProperty(string property, string value) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteValue(value); + + return this; + } + + IObjectWriter IObjectWriter.WriteProperty(string property, double value) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteValue(value); + + return this; + } + + IObjectWriter IObjectWriter.WriteProperty(string property, long value) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteValue(value); + + return this; + } + + IObjectWriter IObjectWriter.WriteProperty(string property, bool value) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteValue(value); + + return this; + } + + IObjectWriter IObjectWriter.WriteProperty(string property, DateTime value) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteValue(value.ToString("o", CultureInfo.InvariantCulture)); + + return this; + } + + IObjectWriter IObjectWriter.WriteProperty(string property, DateTimeOffset value) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteValue(value.ToString("o", CultureInfo.InvariantCulture)); + + return this; + } + + IObjectWriter IObjectWriter.WriteProperty(string property, TimeSpan value) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteValue(value); + + return this; + } + + IObjectWriter IObjectWriter.WriteObject(string property, Action objectWriter) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteStartObject(); + + objectWriter?.Invoke(this); + + jsonWriter.WriteEndObject(); + + return this; + } + + IObjectWriter IObjectWriter.WriteArray(string property, Action arrayWriter) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteStartArray(); + + arrayWriter?.Invoke(this); + + jsonWriter.WriteEndArray(); + + return this; + } + + IArrayWriter IArrayWriter.WriteObject(string property, Action objectWriter) + { + jsonWriter.WritePropertyName(property); + jsonWriter.WriteStartObject(); + + objectWriter?.Invoke(this); + + jsonWriter.WriteEndObject(); + + return this; + } + + public override string ToString() + { + jsonWriter.WriteEndObject(); + + var result = textWriter.ToString(); + + if (extraLine) + { + result += Environment.NewLine; + } + + return result; + } + } +} diff --git a/src/Squidex.Infrastructure/Log/SemanticLog.cs b/src/Squidex.Infrastructure/Log/SemanticLog.cs new file mode 100644 index 000000000..f335d3edd --- /dev/null +++ b/src/Squidex.Infrastructure/Log/SemanticLog.cs @@ -0,0 +1,86 @@ +// ========================================================================== +// SemanticLog.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using System.Collections.Generic; +using System.Linq; + +namespace Squidex.Infrastructure.Log +{ + public sealed class SemanticLog : ISemanticLog + { + private readonly IEnumerable channels; + private readonly IEnumerable appenders; + private readonly Func writerFactory; + + public SemanticLog( + IEnumerable channels, + IEnumerable appenders, + Func writerFactory) + { + Guard.NotNull(channels, nameof(channels)); + Guard.NotNull(appenders, nameof(appenders)); + + this.channels = channels; + this.appenders = appenders; + this.writerFactory = writerFactory; + } + + public void Log(SemanticLogLevel logLevel, Action action) + { + Guard.NotNull(action, nameof(action)); + + var formattedText = FormatText(logLevel, action); + + List exceptions = null; + + foreach (var channel in channels) + { + try + { + channel.Log(logLevel, formattedText); + } + catch (Exception ex) + { + if (exceptions == null) + { + exceptions = new List(); + } + + exceptions.Add(ex); + } + } + + if (exceptions != null && exceptions.Count > 0) + { + throw new AggregateException("An error occurred while writing to logger(s).", exceptions); + } + } + + private string FormatText(SemanticLogLevel logLevel, Action objectWriter) + { + var writer = writerFactory(); + + writer.WriteProperty(nameof(logLevel), logLevel.ToString()); + + objectWriter(writer); + + foreach (var appender in appenders) + { + appender.Append(writer); + } + + return writer.ToString(); + } + + public ISemanticLog CreateScope(Action objectWriter) + { + return new SemanticLog(channels, appenders.Union(new ILogAppender[] { new ConstantsLogWriter(objectWriter) }).ToArray(), writerFactory); + } + } +} diff --git a/src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs b/src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs new file mode 100644 index 000000000..51ffdf6e6 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs @@ -0,0 +1,125 @@ +// ========================================================================== +// SemanticLogExtensions.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using System.Diagnostics; + +// ReSharper disable InvertIf + +namespace Squidex.Infrastructure.Log +{ + public static class SemanticLogExtensions + { + public static void LogTrace(this ISemanticLog log, Action objectWriter) + { + log.Log(SemanticLogLevel.Trace, objectWriter); + } + + public static IDisposable MeasureTrace(this ISemanticLog log, Action objectWriter) + { + return new TimeMeasurer(log, SemanticLogLevel.Trace, objectWriter); + } + + public static void LogDebug(this ISemanticLog log, Action objectWriter) + { + log.Log(SemanticLogLevel.Debug, objectWriter); + } + + public static IDisposable MeasureDebug(this ISemanticLog log, Action objectWriter) + { + return new TimeMeasurer(log, SemanticLogLevel.Debug, objectWriter); + } + + public static void LogInformation(this ISemanticLog log, Action objectWriter) + { + log.Log(SemanticLogLevel.Information, objectWriter); + } + + public static IDisposable MeasureInformation(this ISemanticLog log, Action objectWriter) + { + return new TimeMeasurer(log, SemanticLogLevel.Information, objectWriter); + } + + public static void LogWarning(this ISemanticLog log, Action objectWriter) + { + log.Log(SemanticLogLevel.Warning, objectWriter); + } + + public static void LogWarning(this ISemanticLog log, Exception exception, Action objectWriter = null) + { + log.Log(SemanticLogLevel.Warning, writer => writer.WriteException(exception, objectWriter)); + } + + public static void LogError(this ISemanticLog log, Action objectWriter) + { + log.Log(SemanticLogLevel.Error, objectWriter); + } + + public static void LogError(this ISemanticLog log, Exception exception, Action objectWriter = null) + { + log.Log(SemanticLogLevel.Error, writer => writer.WriteException(exception, objectWriter)); + } + + public static void LogFatal(this ISemanticLog log, Action objectWriter) + { + log.Log(SemanticLogLevel.Fatal, objectWriter); + } + + public static void LogFatal(this ISemanticLog log, Exception exception, Action objectWriter = null) + { + log.Log(SemanticLogLevel.Fatal, writer => writer.WriteException(exception, objectWriter)); + } + + private static void WriteException(this IObjectWriter writer, Exception exception, Action objectWriter) + { + objectWriter?.Invoke(writer); + + if (exception != null) + { + writer.WriteException(exception); + } + } + + public static IObjectWriter WriteException(this IObjectWriter writer, Exception exception) + { + return writer.WriteObject(nameof(exception), inner => + { + inner.WriteProperty("message", exception.Message); + inner.WriteProperty("stackTrace", exception.StackTrace); + }); + } + + private sealed class TimeMeasurer : IDisposable + { + private readonly Stopwatch watch = Stopwatch.StartNew(); + private readonly SemanticLogLevel logLevel; + private readonly Action objectWriter; + private readonly ISemanticLog log; + + public TimeMeasurer(ISemanticLog log, SemanticLogLevel logLevel, Action objectWriter) + { + this.logLevel = logLevel; + this.log = log; + + this.objectWriter = objectWriter; + } + + public void Dispose() + { + watch.Stop(); + + log.Log(logLevel, writer => + { + objectWriter?.Invoke(writer); + + writer.WriteProperty("elapsedMs", watch.ElapsedMilliseconds); + }); + } + } + } +} diff --git a/src/Squidex.Infrastructure/Log/SemanticLogLevel.cs b/src/Squidex.Infrastructure/Log/SemanticLogLevel.cs new file mode 100644 index 000000000..aa724f5db --- /dev/null +++ b/src/Squidex.Infrastructure/Log/SemanticLogLevel.cs @@ -0,0 +1,19 @@ +// ========================================================================== +// SemanticLogLevel.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== +namespace Squidex.Infrastructure.Log +{ + public enum SemanticLogLevel + { + Trace, + Debug, + Information, + Warning, + Error, + Fatal + } +} diff --git a/src/Squidex.Infrastructure/Log/TimestampLogAppender.cs b/src/Squidex.Infrastructure/Log/TimestampLogAppender.cs new file mode 100644 index 000000000..9eab14555 --- /dev/null +++ b/src/Squidex.Infrastructure/Log/TimestampLogAppender.cs @@ -0,0 +1,34 @@ +// ========================================================================== +// TimestampLogAppender.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; + +namespace Squidex.Infrastructure.Log +{ + public sealed class TimestampLogAppender : ILogAppender + { + private readonly Func timestamp; + + public TimestampLogAppender() + : this(() => DateTimeOffset.UtcNow.ToUnixTimeSeconds()) + { + } + + public TimestampLogAppender(Func timestamp) + { + Guard.NotNull(timestamp, nameof(timestamp)); + + this.timestamp = timestamp; + } + + public void Append(IObjectWriter writer) + { + writer.WriteProperty("timestamp", timestamp()); + } + } +} diff --git a/src/Squidex.Read.MongoDb/Contents/Visitors/FindExtensions.cs b/src/Squidex.Read.MongoDb/Contents/Visitors/FindExtensions.cs index da90bb509..3368d5570 100644 --- a/src/Squidex.Read.MongoDb/Contents/Visitors/FindExtensions.cs +++ b/src/Squidex.Read.MongoDb/Contents/Visitors/FindExtensions.cs @@ -51,6 +51,10 @@ namespace Squidex.Read.MongoDb.Contents.Visitors { cursor = cursor.Skip((int)skip.Value); } + else + { + cursor = cursor.Skip(null); + } return cursor; } diff --git a/src/Squidex/Config/Domain/InfrastructureModule.cs b/src/Squidex/Config/Domain/InfrastructureModule.cs index 87b40ebad..fdf25bc86 100644 --- a/src/Squidex/Config/Domain/InfrastructureModule.cs +++ b/src/Squidex/Config/Domain/InfrastructureModule.cs @@ -6,12 +6,14 @@ // All rights reserved. // ========================================================================== +using System; using Autofac; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Mvc.Infrastructure; using Microsoft.Extensions.Caching.Memory; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Options; +using Newtonsoft.Json; using NodaTime; using Squidex.Core.Schemas; using Squidex.Core.Schemas.Json; @@ -19,6 +21,8 @@ using Squidex.Infrastructure; using Squidex.Infrastructure.Caching; using Squidex.Infrastructure.CQRS.Commands; using Squidex.Infrastructure.CQRS.Events; +using Squidex.Infrastructure.Log; +using IntrospectionExtensions = System.Reflection.IntrospectionExtensions; // ReSharper disable UnusedAutoPropertyAccessor.Local @@ -35,6 +39,39 @@ namespace Squidex.Config.Domain protected override void Load(ContainerBuilder builder) { + if (Configuration.GetValue("squidex:logging:human")) + { + builder.Register(c => new Func(() => new JsonLogWriter(Formatting.Indented, true))) + .AsSelf() + .SingleInstance(); + } + else + { + builder.Register(c => new Func(() => new JsonLogWriter())) + .AsSelf() + .SingleInstance(); + } + + builder.Register(c => new ApplicationInfoLogAppender(IntrospectionExtensions.GetTypeInfo(typeof(InfrastructureModule)).Assembly)) + .As() + .SingleInstance(); + + builder.Register(c => new TimestampLogAppender()) + .As() + .SingleInstance(); + + builder.RegisterType() + .As() + .SingleInstance(); + + builder.RegisterType() + .As() + .SingleInstance(); + + builder.RegisterType() + .As() + .SingleInstance(); + builder.Register(c => SystemClock.Instance) .As() .SingleInstance(); diff --git a/src/Squidex/Controllers/UI/Account/AccountController.cs b/src/Squidex/Controllers/UI/Account/AccountController.cs index b701907d1..0a68327ca 100644 --- a/src/Squidex/Controllers/UI/Account/AccountController.cs +++ b/src/Squidex/Controllers/UI/Account/AccountController.cs @@ -22,6 +22,7 @@ using Microsoft.Extensions.Options; using Squidex.Config; using Squidex.Config.Identity; using Squidex.Core.Identity; +using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Tasks; // ReSharper disable InvertIf @@ -33,12 +34,11 @@ namespace Squidex.Controllers.UI.Account [SwaggerIgnore] public sealed class AccountController : Controller { - private static readonly EventId IdentityEventId = new EventId(8000, "IdentityEventId"); private readonly SignInManager signInManager; private readonly UserManager userManager; private readonly IOptions identityOptions; private readonly IOptions urlOptions; - private readonly ILogger logger; + private readonly ISemanticLog log; private readonly IIdentityServerInteractionService interactions; public AccountController( @@ -46,10 +46,10 @@ namespace Squidex.Controllers.UI.Account UserManager userManager, IOptions identityOptions, IOptions urlOptions, - ILogger logger, + ISemanticLog log, IIdentityServerInteractionService interactions) { - this.logger = logger; + this.log = log; this.urlOptions = urlOptions; this.userManager = userManager; this.interactions = interactions; @@ -264,14 +264,19 @@ namespace Squidex.Controllers.UI.Account errorMessageBuilder.AppendLine(error.Description); } - logger.LogError(IdentityEventId, "Operation '{0}' failed with errors: {1}", operationName, errorMessageBuilder.ToString()); + log.LogError(w => w + .WriteProperty("action", operationName) + .WriteProperty("status", "Failed") + .WriteProperty("message", errorMessageBuilder.ToString())); } return result.Succeeded; } - catch (Exception e) + catch (Exception ex) { - logger.LogError(IdentityEventId, e, "Operation '{0}' failed with exception", operationName); + log.LogError(ex, w => w + .WriteProperty("action", operationName) + .WriteProperty("status", "Failed")); return false; } diff --git a/src/Squidex/Pipeline/WebpackMiddleware.cs b/src/Squidex/Pipeline/WebpackMiddleware.cs index a65f77cd9..043b1e466 100644 --- a/src/Squidex/Pipeline/WebpackMiddleware.cs +++ b/src/Squidex/Pipeline/WebpackMiddleware.cs @@ -10,7 +10,6 @@ using System; using System.IO; using System.Threading.Tasks; using Microsoft.AspNetCore.Http; -using Microsoft.Extensions.Logging; // ReSharper disable LoopCanBeConvertedToQuery @@ -23,12 +22,9 @@ namespace Squidex.Pipeline private static readonly string[] Scripts = { "shims.js", "app.js" }; private static readonly string[] Styles = new string[0]; private readonly RequestDelegate next; - private readonly ILogger logger; - public WebpackMiddleware(RequestDelegate next, ILoggerFactory loggerFactory) + public WebpackMiddleware(RequestDelegate next) { - logger = loggerFactory.CreateLogger(); - this.next = next; } @@ -76,15 +72,13 @@ namespace Squidex.Pipeline context.Response.Body = body; } - private string InjectStyles(string response) + private static string InjectStyles(string response) { if (!response.Contains("")) { return response; } - - logger.LogInformation("A full html page is returned so the necessary styles for webpack will be injected"); - + var stylesTag = string.Empty; foreach (var file in Styles) @@ -94,20 +88,16 @@ namespace Squidex.Pipeline response = response.Replace("", $"{stylesTag}"); - logger.LogInformation($"Inject style {stylesTag} as a last element in the head "); - return response; } - private string InjectScripts(string response) + private static string InjectScripts(string response) { if (!response.Contains("")) { return response; } - - logger.LogInformation("A full html page is returned so the necessary script for webpack will be injected"); - + var scriptsTag = string.Empty; foreach (var file in Scripts) @@ -117,8 +107,6 @@ namespace Squidex.Pipeline response = response.Replace("", $"{scriptsTag}"); - logger.LogInformation($"Inject script {scriptsTag} as a last element in the body "); - return response; } diff --git a/src/Squidex/Startup.cs b/src/Squidex/Startup.cs index 2699676b9..e8412cbba 100644 --- a/src/Squidex/Startup.cs +++ b/src/Squidex/Startup.cs @@ -22,6 +22,8 @@ using Squidex.Config.Domain; using Squidex.Config.Identity; using Squidex.Config.Swagger; using Squidex.Config.Web; +using Squidex.Infrastructure.Log; +using Squidex.Infrastructure.Log.Adapter; // ReSharper disable ConvertClosureToMethodGroup // ReSharper disable AccessToModifiedClosure @@ -95,8 +97,7 @@ namespace Squidex public void Configure(IApplicationBuilder app, ILoggerFactory loggerFactory) { - loggerFactory.AddConsole(LogLevel.Debug); - loggerFactory.AddDebug(); + loggerFactory.AddSemanticLog(app.ApplicationServices.GetRequiredService()); app.TestExternalSystems(); diff --git a/src/Squidex/appsettings.json b/src/Squidex/appsettings.json index c72c9e935..5671c99fd 100644 --- a/src/Squidex/appsettings.json +++ b/src/Squidex/appsettings.json @@ -3,6 +3,9 @@ "urls": { "baseUrl": "http://localhost:5000" }, + "logging": { + "human": true + }, "clusterer": { "type": "none", "redis": { diff --git a/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExceptionHandlerTests.cs b/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExceptionHandlerTests.cs index e2290acb2..e89110a8b 100644 --- a/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExceptionHandlerTests.cs +++ b/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExceptionHandlerTests.cs @@ -8,43 +8,38 @@ using System; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; using Xunit; using System.Collections.Generic; using System.Linq; using Moq; +using Squidex.Infrastructure.Log; namespace Squidex.Infrastructure.CQRS.Commands { public class LogExceptionHandlerTests { - private readonly MyLogger logger = new MyLogger(); + private readonly MyLog log = new MyLog(); private readonly LogExceptionHandler sut; private readonly ICommand command = new Mock().Object; - private sealed class MyLogger : ILogger + private sealed class MyLog : ISemanticLog { - public HashSet LogLevels { get; } = new HashSet(); + public HashSet LogLevels { get; } = new HashSet(); - public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatterr) + public void Log(SemanticLogLevel logLevel, Action action) { LogLevels.Add(logLevel); } - public bool IsEnabled(LogLevel logLevel) + public ISemanticLog CreateScope(Action objectWriter) { - return false; - } - - public IDisposable BeginScope(TState state) - { - return null; + throw new NotSupportedException(); } } public LogExceptionHandlerTests() { - sut = new LogExceptionHandler(logger); + sut = new LogExceptionHandler(log); } [Fact] @@ -57,7 +52,7 @@ namespace Squidex.Infrastructure.CQRS.Commands var isHandled = await sut.HandleAsync(context); Assert.False(isHandled); - Assert.Equal(0, logger.LogLevels.Count); + Assert.Equal(0, log.LogLevels.Count); } [Fact] @@ -70,7 +65,7 @@ namespace Squidex.Infrastructure.CQRS.Commands var isHandled = await sut.HandleAsync(context); Assert.False(isHandled); - Assert.Equal(new[] { LogLevel.Error }, logger.LogLevels.ToArray()); + Assert.Equal(new[] { SemanticLogLevel.Error }, log.LogLevels.ToArray()); } [Fact] @@ -81,7 +76,7 @@ namespace Squidex.Infrastructure.CQRS.Commands var isHandled = await sut.HandleAsync(context); Assert.False(isHandled); - Assert.Equal(new[] { LogLevel.Critical }, logger.LogLevels.ToArray()); + Assert.Equal(new[] { SemanticLogLevel.Fatal }, log.LogLevels.ToArray()); } } } \ No newline at end of file diff --git a/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExecutingHandlerTests.cs b/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExecutingHandlerTests.cs index cbf04c40b..5c2b8fd2c 100644 --- a/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExecutingHandlerTests.cs +++ b/tests/Squidex.Infrastructure.Tests/CQRS/Commands/LogExecutingHandlerTests.cs @@ -8,41 +8,36 @@ using System; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; using Moq; +using Squidex.Infrastructure.Log; using Xunit; namespace Squidex.Infrastructure.CQRS.Commands { public class LogExecutingHandlerTests { - private readonly MyLogger logger = new MyLogger(); + private readonly MyLog log = new MyLog(); private readonly LogExecutingHandler sut; private readonly ICommand command = new Mock().Object; - private sealed class MyLogger : ILogger + private sealed class MyLog : ISemanticLog { public int LogCount { get; private set; } - public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatterr) + public void Log(SemanticLogLevel logLevel, Action action) { LogCount++; } - public bool IsEnabled(LogLevel logLevel) + public ISemanticLog CreateScope(Action objectWriter) { - return false; - } - - public IDisposable BeginScope(TState state) - { - return null; + throw new NotSupportedException(); } } public LogExecutingHandlerTests() { - sut = new LogExecutingHandler(logger); + sut = new LogExecutingHandler(log); } [Fact] @@ -53,7 +48,7 @@ namespace Squidex.Infrastructure.CQRS.Commands var isHandled = await sut.HandleAsync(context); Assert.False(isHandled); - Assert.Equal(1, logger.LogCount); + Assert.Equal(1, log.LogCount); } } } diff --git a/tests/Squidex.Infrastructure.Tests/CQRS/Events/EventReceiverTests.cs b/tests/Squidex.Infrastructure.Tests/CQRS/Events/EventReceiverTests.cs index 2a8b25b61..60e918e4e 100644 --- a/tests/Squidex.Infrastructure.Tests/CQRS/Events/EventReceiverTests.cs +++ b/tests/Squidex.Infrastructure.Tests/CQRS/Events/EventReceiverTests.cs @@ -10,8 +10,8 @@ using System; using System.Collections.Generic; using System.Reactive.Linq; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; using Moq; +using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Tasks; using Xunit; @@ -30,33 +30,26 @@ namespace Squidex.Infrastructure.CQRS.Events public long LastHandledEventNumber { get; set; } public bool IsStopped { get; set; } - public bool IsResetting { get; set; } public string Name { get; set; } - public string Error { get; set; } } - private sealed class MyLogger : ILogger + private sealed class MyLog : ISemanticLog { - public Dictionary LogCount { get; } = new Dictionary(); + public Dictionary LogCount { get; } = new Dictionary(); - public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatterr) + public void Log(SemanticLogLevel logLevel, Action action) { var count = LogCount.GetOrDefault(logLevel); LogCount[logLevel] = count + 1; } - public bool IsEnabled(LogLevel logLevel) - { - return false; - } - - public IDisposable BeginScope(TState state) + public ISemanticLog CreateScope(Action objectWriter) { - return null; + throw new NotSupportedException(); } } @@ -72,7 +65,7 @@ namespace Squidex.Infrastructure.CQRS.Events private readonly Envelope envelope2 = new Envelope(new MyEvent()); private readonly Envelope envelope3 = new Envelope(new MyEvent()); private readonly EventReceiver sut; - private readonly MyLogger logger = new MyLogger(); + private readonly MyLog log = new MyLog(); private readonly StoredEvent[] events; private readonly MyEventConsumerInfo consumerInfo = new MyEventConsumerInfo(); private readonly string consumerName; @@ -97,7 +90,7 @@ namespace Squidex.Infrastructure.CQRS.Events formatter.Setup(x => x.Parse(eventData2)).Returns(envelope2); formatter.Setup(x => x.Parse(eventData3)).Returns(envelope3); - sut = new EventReceiver(formatter.Object, eventStore.Object, eventNotifier.Object, eventConsumerInfoRepository.Object, logger); + sut = new EventReceiver(formatter.Object, eventStore.Object, eventNotifier.Object, eventConsumerInfoRepository.Object, log); } public void Dispose() @@ -123,8 +116,8 @@ namespace Squidex.Infrastructure.CQRS.Events await Task.Delay(20); - Assert.Equal(1, logger.LogCount.Count); - Assert.Equal(6, logger.LogCount[LogLevel.Debug]); + Assert.Equal(1, log.LogCount.Count); + Assert.Equal(6, log.LogCount[SemanticLogLevel.Debug]); eventConsumer.Verify(x => x.On(envelope1), Times.Once()); eventConsumer.Verify(x => x.On(envelope2), Times.Once()); @@ -143,9 +136,9 @@ namespace Squidex.Infrastructure.CQRS.Events await Task.Delay(20); - Assert.Equal(2, logger.LogCount.Count); - Assert.Equal(2, logger.LogCount[LogLevel.Error]); - Assert.Equal(3, logger.LogCount[LogLevel.Debug]); + Assert.Equal(2, log.LogCount.Count); + Assert.Equal(2, log.LogCount[SemanticLogLevel.Error]); + Assert.Equal(3, log.LogCount[SemanticLogLevel.Debug]); eventConsumer.Verify(x => x.On(envelope1), Times.Once()); eventConsumer.Verify(x => x.On(envelope2), Times.Once()); @@ -165,9 +158,9 @@ namespace Squidex.Infrastructure.CQRS.Events await Task.Delay(20); - Assert.Equal(2, logger.LogCount.Count); - Assert.Equal(2, logger.LogCount[LogLevel.Error]); - Assert.Equal(2, logger.LogCount[LogLevel.Debug]); + Assert.Equal(2, log.LogCount.Count); + Assert.Equal(2, log.LogCount[SemanticLogLevel.Error]); + Assert.Equal(2, log.LogCount[SemanticLogLevel.Debug]); eventConsumer.Verify(x => x.On(envelope1), Times.Once()); eventConsumer.Verify(x => x.On(envelope2), Times.Never()); @@ -188,8 +181,8 @@ namespace Squidex.Infrastructure.CQRS.Events await Task.Delay(20); - Assert.Equal(1, logger.LogCount.Count); - Assert.Equal(8, logger.LogCount[LogLevel.Debug]); + Assert.Equal(1, log.LogCount.Count); + Assert.Equal(8, log.LogCount[SemanticLogLevel.Debug]); eventConsumer.Verify(x => x.On(envelope1), Times.Once()); eventConsumer.Verify(x => x.On(envelope2), Times.Once()); diff --git a/tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs b/tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs new file mode 100644 index 000000000..606b31eb5 --- /dev/null +++ b/tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs @@ -0,0 +1,163 @@ +// ========================================================================== +// JsonLogWriterTests.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using Newtonsoft.Json; +using System; +using Xunit; + +namespace Squidex.Infrastructure.Log +{ + public class JsonLogWriterTests + { + private readonly IObjectWriter sut = new JsonLogWriter(); + + [Fact] + public void Should_write_boolean_property() + { + var result = sut.WriteProperty("property", true).ToString(); + + Assert.Equal(@"{""property"":true}", result); + } + + [Fact] + public void Should_write_long_property() + { + var result = sut.WriteProperty("property", 120).ToString(); + + Assert.Equal(@"{""property"":120}", result); + } + + [Fact] + public void Should_write_double_property() + { + var result = sut.WriteProperty("property", 1.5).ToString(); + + Assert.Equal(@"{""property"":1.5}", result); + } + + [Fact] + public void Should_write_string_property() + { + var result = sut.WriteProperty("property", "my-string").ToString(); + + Assert.Equal(@"{""property"":""my-string""}", result); + } + + [Fact] + public void Should_write_timespan_property() + { + var result = sut.WriteProperty("property", new TimeSpan(1, 40, 30, 20, 100)).ToString(); + + Assert.Equal(@"{""property"":""2.16:30:20.1000000""}", result); + } + + [Fact] + public void Should_write_datetimeoffset_property() + { + var value = DateTimeOffset.UtcNow; + var result = sut.WriteProperty("property", value).ToString(); + + Assert.Equal($"{{\"property\":\"{value.ToString("o")}\"}}", result); + } + + [Fact] + public void Should_write_date_property() + { + var value = DateTime.UtcNow; + var result = sut.WriteProperty("property", value).ToString(); + + Assert.Equal($"{{\"property\":\"{value.ToString("o")}\"}}", result); + } + + [Fact] + public void Should_write_boolean_value() + { + var result = sut.WriteArray("property", a => a.WriteValue(true)).ToString(); + + Assert.Equal(@"{""property"":[true]}", result); + } + + [Fact] + public void Should_write_long_value() + { + var result = sut.WriteArray("property", a => a.WriteValue(120)).ToString(); + + Assert.Equal(@"{""property"":[120]}", result); + } + + [Fact] + public void Should_write_double_value() + { + var result = sut.WriteArray("property", a => a.WriteValue(1.5)).ToString(); + + Assert.Equal(@"{""property"":[1.5]}", result); + } + + [Fact] + public void Should_write_string_value() + { + var result = sut.WriteArray("property", a => a.WriteValue("my-string")).ToString(); + + Assert.Equal(@"{""property"":[""my-string""]}", result); + } + + [Fact] + public void Should_write_timespan_value() + { + var result = sut.WriteArray("property", a => a.WriteValue(new TimeSpan(1, 40, 30, 20, 100))).ToString(); + + Assert.Equal(@"{""property"":[""2.16:30:20.1000000""]}", result); + } + + [Fact] + public void Should_write_datetimeoffset_value() + { + var value = DateTimeOffset.UtcNow; + var result = sut.WriteArray("property", a => a.WriteValue(value)).ToString(); + + Assert.Equal($"{{\"property\":[\"{value.ToString("o")}\"]}}", result); + } + + [Fact] + public void Should_write_date_value() + { + var value = DateTime.UtcNow; + var result = sut.WriteArray("property", a => a.WriteValue(value)).ToString(); + + Assert.Equal($"{{\"property\":[\"{value.ToString("o")}\"]}}", result); + } + + [Fact] + public void Should_write_nested_object() + { + var result = sut.WriteObject("property", a => a.WriteProperty("nested", "my-string")).ToString(); + + Assert.Equal(@"{""property"":{""nested"":""my-string""}}", result); + } + + [Fact] + public void Should_write_pretty_json() + { + IObjectWriter prettySut = new JsonLogWriter(Formatting.Indented, false); + + var result = prettySut.WriteProperty("property", 1.5).ToString(); + + Assert.Equal(@"{NL ""property"": 1.5NL}".Replace("NL", Environment.NewLine), result); + } + + [Fact] + public void Should_write_extra_line_after_object() + { + IObjectWriter prettySut = new JsonLogWriter(Formatting.None, true); + + var result = prettySut.WriteProperty("property", 1.5).ToString(); + + Assert.Equal(@"{""property"":1.5}NL".Replace("NL", Environment.NewLine), result); + } + } +} diff --git a/tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs b/tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs new file mode 100644 index 000000000..9e6f11e68 --- /dev/null +++ b/tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs @@ -0,0 +1,300 @@ +// ========================================================================== +// SemanticLogTests.cs +// Squidex Headless CMS +// ========================================================================== +// Copyright (c) Squidex Group +// All rights reserved. +// ========================================================================== + +using System; +using System.Collections.Generic; +using System.Reflection; +using Microsoft.Extensions.Logging; +using Moq; +using Squidex.Infrastructure.Log.Adapter; +using Xunit; + +namespace Squidex.Infrastructure.Log +{ + public class SemanticLogTests + { + private readonly List appenders = new List(); + private readonly List channels = new List(); + private readonly Lazy log; + private readonly Mock channel = new Mock(); + private string output; + + public SemanticLog Log + { + get { return log.Value; } + } + + public SemanticLogTests() + { + channels.Add(channel.Object); + + channel.Setup(x => x.Log(It.IsAny(), It.IsAny())).Callback( + new Action((level, message) => + { + output = message; + })); + + log = new Lazy(() => new SemanticLog(channels, appenders, () => new JsonLogWriter())); + } + + [Fact] + public void Should_log_timestamp() + { + appenders.Add(new TimestampLogAppender(() => 1500)); + + Log.LogFatal(w => {}); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Fatal") + .WriteProperty("timestamp", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_values_with_appender() + { + appenders.Add(new ConstantsLogWriter(w => w.WriteProperty("logValue", 1500))); + + Log.LogFatal(m => { }); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Fatal") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_application_info() + { + appenders.Add(new ApplicationInfoLogAppender(GetType().GetTypeInfo().Assembly)); + + Log.LogFatal(m => { }); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Fatal") + .WriteProperty("applicationName", "Squidex.Infrastructure.Tests") + .WriteProperty("applicationVersion", "1.0.0.0")); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_trace() + { + Log.LogTrace(w => w.WriteProperty("logValue", 1500)); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Trace") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_debug() + { + Log.LogDebug(w => w.WriteProperty("logValue", 1500)); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Debug") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_information() + { + Log.LogInformation(w => w.WriteProperty("logValue", 1500)); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Information") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_warning() + { + Log.LogWarning(w => w.WriteProperty("logValue", 1500)); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Warning") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_warning_exception() + { + var exception = new InvalidOperationException(); + + Log.LogWarning(exception); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Warning") + .WriteException(exception)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_error() + { + Log.LogError(w => w.WriteProperty("logValue", 1500)); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Error") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_error_exception() + { + var exception = new InvalidOperationException(); + + Log.LogError(exception); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Error") + .WriteException(exception)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_fatal() + { + Log.LogFatal(w => w.WriteProperty("logValue", 1500)); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Fatal") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_fatal_exception() + { + var exception = new InvalidOperationException(); + + Log.LogFatal(exception); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Fatal") + .WriteException(exception)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_nothing_when_exception_is_null() + { + Log.LogFatal((Exception)null); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Fatal")); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_measure_trace() + { + Log.MeasureTrace(w => w.WriteProperty("message", "My Message")).Dispose(); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Trace") + .WriteProperty("message", "My Message") + .WriteProperty("elapsedMs", 0)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_measure_debug() + { + Log.MeasureDebug(w => w.WriteProperty("message", "My Message")).Dispose(); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Debug") + .WriteProperty("message", "My Message") + .WriteProperty("elapsedMs", 0)); + + Assert.True(output.StartsWith(expected.Substring(0, 55))); + } + + [Fact] + public void Should_measure_information() + { + Log.MeasureInformation(w => w.WriteProperty("message", "My Message")).Dispose(); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Information") + .WriteProperty("message", "My Message") + .WriteProperty("elapsedMs", 0)); + + Assert.Equal(expected, output); + } + + [Fact] + public void Should_log_with_extensions_logger() + { + var exception = new InvalidOperationException(); + + var loggerFactory = new LoggerFactory().AddSemanticLog(Log); + var loggerInstance = loggerFactory.CreateLogger(); + + loggerInstance.LogCritical(new EventId(123, "EventName"), exception, "Log {0}", 123); + + var expected = + MakeTestCall(w => w + .WriteProperty("logLevel", "Fatal") + .WriteProperty("message", "Log 123") + .WriteObject("eventId", e => e + .WriteProperty("id", 123) + .WriteProperty("name", "EventName")) + .WriteException(exception) + .WriteProperty("category", "Squidex.Infrastructure.Log.SemanticLogTests")); + + Assert.Equal(expected, output); + } + + private static string MakeTestCall(Action writer) + { + IObjectWriter sut = new JsonLogWriter(); + + writer(sut); + + return sut.ToString(); + } + } +}