diff --git a/Directory.build.props b/Directory.build.props new file mode 100644 index 000000000..36f26e55b --- /dev/null +++ b/Directory.build.props @@ -0,0 +1,5 @@ + + + 7.3 + + \ No newline at end of file diff --git a/src/Squidex.Domain.Apps.Entities/Backup/BackupGrain.cs b/src/Squidex.Domain.Apps.Entities/Backup/BackupGrain.cs index 4c511e328..f1bff2c44 100644 --- a/src/Squidex.Domain.Apps.Entities/Backup/BackupGrain.cs +++ b/src/Squidex.Domain.Apps.Entities/Backup/BackupGrain.cs @@ -171,10 +171,10 @@ namespace Squidex.Domain.Apps.Entities.Backup } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, job.Id.ToString(), (ctx, w) => w .WriteProperty("action", "makeBackup") .WriteProperty("status", "failed") - .WriteProperty("backupId", job.Id.ToString())); + .WriteProperty("backupId", ctx)); job.Status = JobStatus.Failed; } diff --git a/src/Squidex.Domain.Apps.Entities/Backup/Helpers/Safe.cs b/src/Squidex.Domain.Apps.Entities/Backup/Helpers/Safe.cs index d599881b6..9019ce27b 100644 --- a/src/Squidex.Domain.Apps.Entities/Backup/Helpers/Safe.cs +++ b/src/Squidex.Domain.Apps.Entities/Backup/Helpers/Safe.cs @@ -22,10 +22,10 @@ namespace Squidex.Domain.Apps.Entities.Backup.Helpers } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, id.ToString(), (logOperationId, w) => w .WriteProperty("action", "deleteArchive") .WriteProperty("status", "failed") - .WriteProperty("operationId", id.ToString())); + .WriteProperty("operationId", logOperationId)); } } @@ -37,10 +37,10 @@ namespace Squidex.Domain.Apps.Entities.Backup.Helpers } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, id.ToString(), (logOperationId, w) => w .WriteProperty("action", "deleteBackup") .WriteProperty("status", "failed") - .WriteProperty("operationId", id.ToString())); + .WriteProperty("operationId", logOperationId)); } } @@ -52,10 +52,10 @@ namespace Squidex.Domain.Apps.Entities.Backup.Helpers } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, id.ToString(), (logOperationId, w) => w .WriteProperty("action", "cleanupRestore") .WriteProperty("status", "failed") - .WriteProperty("operationId", id.ToString())); + .WriteProperty("operationId", logOperationId)); } } } diff --git a/src/Squidex.Domain.Apps.Entities/Backup/RestoreGrain.cs b/src/Squidex.Domain.Apps.Entities/Backup/RestoreGrain.cs index fc22d39a9..f9e4e3f82 100644 --- a/src/Squidex.Domain.Apps.Entities/Backup/RestoreGrain.cs +++ b/src/Squidex.Domain.Apps.Entities/Backup/RestoreGrain.cs @@ -135,6 +135,8 @@ namespace Squidex.Domain.Apps.Entities.Backup private async Task ProcessAsync() { + var logContext = (jobId: CurrentJob.Id.ToString(), jobUrl: CurrentJob.Url.ToString()); + using (Profiler.StartSession()) { try @@ -145,11 +147,11 @@ namespace Squidex.Domain.Apps.Entities.Backup Log(" * Restore all objects like app, schemas and contents"); Log(" * Complete the restore operation for all objects"); - log.LogInformation(w => w + log.LogInformation(logContext, (ctx, w) => w .WriteProperty("action", "restore") .WriteProperty("status", "started") - .WriteProperty("operationId", CurrentJob.Id.ToString()) - .WriteProperty("url", CurrentJob.Url.ToString())); + .WriteProperty("operationId", ctx.jobId) + .WriteProperty("url", ctx.jobUrl)); using (Profiler.Trace("Download")) { @@ -190,12 +192,12 @@ namespace Squidex.Domain.Apps.Entities.Backup Log("Completed, Yeah!"); - log.LogInformation(w => + log.LogInformation(logContext, (ctx, w) => { w.WriteProperty("action", "restore"); w.WriteProperty("status", "completed"); - w.WriteProperty("operationId", CurrentJob.Id.ToString()); - w.WriteProperty("url", CurrentJob.Url.ToString()); + w.WriteProperty("operationId", ctx.jobId); + w.WriteProperty("url", ctx.jobUrl); Profiler.Session?.Write(w); }); @@ -215,12 +217,12 @@ namespace Squidex.Domain.Apps.Entities.Backup CurrentJob.Status = JobStatus.Failed; - log.LogError(ex, w => + log.LogError(ex, logContext, (ctx, w) => { w.WriteProperty("action", "retore"); w.WriteProperty("status", "failed"); - w.WriteProperty("operationId", CurrentJob.Id.ToString()); - w.WriteProperty("url", CurrentJob.Url.ToString()); + w.WriteProperty("operationId", ctx.jobId); + w.WriteProperty("url", ctx.jobUrl); Profiler.Session?.Write(w); }); diff --git a/src/Squidex.Domain.Apps.Entities/Contents/ContentSchedulerGrain.cs b/src/Squidex.Domain.Apps.Entities/Contents/ContentSchedulerGrain.cs index 4f2f92982..d1885adcd 100644 --- a/src/Squidex.Domain.Apps.Entities/Contents/ContentSchedulerGrain.cs +++ b/src/Squidex.Domain.Apps.Entities/Contents/ContentSchedulerGrain.cs @@ -83,10 +83,10 @@ namespace Squidex.Domain.Apps.Entities.Contents } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, content.Id.ToString(), (logContentId, w) => w .WriteProperty("action", "ChangeStatusScheduled") .WriteProperty("status", "Failed") - .WriteProperty("contentId", content.Id.ToString())); + .WriteProperty("contentId", logContentId)); } }); }); diff --git a/src/Squidex.Infrastructure.Redis/RedisSubscription.cs b/src/Squidex.Infrastructure.Redis/RedisSubscription.cs index dc8c10be2..98a15f343 100644 --- a/src/Squidex.Infrastructure.Redis/RedisSubscription.cs +++ b/src/Squidex.Infrastructure.Redis/RedisSubscription.cs @@ -54,10 +54,10 @@ namespace Squidex.Infrastructure } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, channelName, (logChannel, w) => w .WriteProperty("action", "PublishRedisMessage") .WriteProperty("status", "Failed") - .WriteProperty("channel", channelName)); + .WriteProperty("channel", logChannel)); } } @@ -76,17 +76,17 @@ namespace Squidex.Infrastructure { subject.OnNext(envelope.Payload); - log.LogDebug(w => w + log.LogDebug(channelName, (logChannel, w) => w .WriteProperty("action", "ReceiveRedisMessage") - .WriteProperty("channel", channelName) + .WriteProperty("channel", logChannel) .WriteProperty("status", "Received")); } } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, channelName, (logChannel, w) => w .WriteProperty("action", "ReceiveRedisMessage") - .WriteProperty("channel", channelName) + .WriteProperty("channel", logChannel) .WriteProperty("status", "Failed")); } } diff --git a/src/Squidex.Infrastructure/Commands/LogCommandMiddleware.cs b/src/Squidex.Infrastructure/Commands/LogCommandMiddleware.cs index eb2f44eb6..0e0d64504 100644 --- a/src/Squidex.Infrastructure/Commands/LogCommandMiddleware.cs +++ b/src/Squidex.Infrastructure/Commands/LogCommandMiddleware.cs @@ -24,47 +24,49 @@ namespace Squidex.Infrastructure.Commands public async Task HandleAsync(CommandContext context, Func next) { + var logContext = (id: context.ContextId.ToString(), command: context.Command.GetType().Name); + try { - log.LogInformation(w => w + log.LogInformation(logContext, (ctx, w) => w .WriteProperty("action", "HandleCommand.") - .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("actionId", ctx.id) .WriteProperty("status", "Started") - .WriteProperty("commandType", context.Command.GetType().Name)); + .WriteProperty("commandType", ctx.command)); - using (log.MeasureInformation(w => w + using (log.MeasureInformation(logContext, (ctx, w) => w .WriteProperty("action", "HandleCommand.") - .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("actionId", ctx.id) .WriteProperty("status", "Completed") - .WriteProperty("commandType", context.Command.GetType().Name))) + .WriteProperty("commandType", ctx.command))) { await next(); } - log.LogInformation(w => w + log.LogInformation(logContext, (ctx, w) => w .WriteProperty("action", "HandleCommand.") - .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("actionId", ctx.id) .WriteProperty("status", "Succeeded") - .WriteProperty("commandType", context.Command.GetType().Name)); + .WriteProperty("commandType", ctx.command)); } catch (Exception ex) { - log.LogError(ex, w => w + log.LogError(ex, logContext, (ctx, w) => w .WriteProperty("action", "HandleCommand.") - .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("actionId", ctx.id) .WriteProperty("status", "Failed") - .WriteProperty("commandType", context.Command.GetType().Name)); + .WriteProperty("commandType", ctx.command)); throw; } if (!context.IsCompleted) { - log.LogFatal(w => w + log.LogFatal(logContext, (ctx, w) => w .WriteProperty("action", "HandleCommand.") - .WriteProperty("actionId", context.ContextId.ToString()) + .WriteProperty("actionId", ctx.id) .WriteProperty("status", "Unhandled") - .WriteProperty("commandType", context.Command.GetType().Name)); + .WriteProperty("commandType", ctx.command)); } } } diff --git a/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs b/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs index 51e584d12..4c6f1c3ab 100644 --- a/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs +++ b/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs @@ -185,19 +185,19 @@ namespace Squidex.Infrastructure.EventSourcing.Grains private async Task ClearAsync() { - var actionId = Guid.NewGuid().ToString(); + var logContext = (actionId: Guid.NewGuid().ToString(), consumer: eventConsumer.Name); - log.LogInformation(w => w + log.LogInformation(logContext, (ctx, w) => w .WriteProperty("action", "EventConsumerReset") - .WriteProperty("actionId", actionId) + .WriteProperty("actionId", ctx.actionId) .WriteProperty("status", "Started") - .WriteProperty("eventConsumer", eventConsumer.Name)); + .WriteProperty("eventConsumer", ctx.consumer)); - using (log.MeasureTrace(w => w + using (log.MeasureTrace(logContext, (ctx, w) => w .WriteProperty("action", "EventConsumerReset") - .WriteProperty("actionId", actionId) + .WriteProperty("actionId", ctx.actionId) .WriteProperty("status", "Completed") - .WriteProperty("eventConsumer", eventConsumer.Name))) + .WriteProperty("eventConsumer", ctx.consumer))) { await eventConsumer.ClearAsync(); } @@ -208,21 +208,23 @@ namespace Squidex.Infrastructure.EventSourcing.Grains var eventId = @event.Headers.EventId().ToString(); var eventType = @event.Payload.GetType().Name; - log.LogInformation(w => w + var logContext = (eventId, eventType, consumer: eventConsumer.Name); + + log.LogInformation(logContext, (ctx, w) => w .WriteProperty("action", "HandleEvent") - .WriteProperty("actionId", eventId) + .WriteProperty("actionId", ctx.eventId) .WriteProperty("status", "Started") - .WriteProperty("eventId", eventId) - .WriteProperty("eventType", eventType) - .WriteProperty("eventConsumer", eventConsumer.Name)); + .WriteProperty("eventId", ctx.eventId) + .WriteProperty("eventType", ctx.eventType) + .WriteProperty("eventConsumer", ctx.consumer)); - using (log.MeasureTrace(w => w + using (log.MeasureTrace(logContext, (ctx, w) => w .WriteProperty("action", "HandleEvent") - .WriteProperty("actionId", eventId) + .WriteProperty("actionId", ctx.eventId) .WriteProperty("status", "Completed") - .WriteProperty("eventId", eventId) - .WriteProperty("eventType", eventType) - .WriteProperty("eventConsumer", eventConsumer.Name))) + .WriteProperty("eventId", ctx.eventId) + .WriteProperty("eventType", ctx.eventType) + .WriteProperty("eventConsumer", ctx.consumer))) { await eventConsumer.On(@event); } diff --git a/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs index b978abf1b..d7acc1b1a 100644 --- a/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs +++ b/src/Squidex.Infrastructure/Log/Adapter/SemanticLogLogger.cs @@ -49,29 +49,31 @@ namespace Squidex.Infrastructure.Log.Adapter break; } - semanticLog.Log(semanticLogLevel, writer => + var context = (eventId, state, exception, formatter); + + semanticLog.Log(semanticLogLevel, context, (ctx, writer) => { - var message = formatter(state, exception); + var message = ctx.formatter(ctx.state, ctx.exception); if (!string.IsNullOrWhiteSpace(message)) { writer.WriteProperty(nameof(message), message); } - if (eventId.Id > 0) + if (ctx.eventId.Id > 0) { - writer.WriteObject(nameof(eventId), eventIdWriter => + writer.WriteObject("eventId", ctx.eventId, (innerEventId, eventIdWriter) => { - eventIdWriter.WriteProperty("id", eventId.Id); + eventIdWriter.WriteProperty("id", innerEventId.Id); - if (!string.IsNullOrWhiteSpace(eventId.Name)) + if (!string.IsNullOrWhiteSpace(innerEventId.Name)) { - eventIdWriter.WriteProperty("name", eventId.Name); + eventIdWriter.WriteProperty("name", innerEventId.Name); } }); } - if (state is IReadOnlyList> parameters) + if (ctx.state is IReadOnlyList> parameters) { foreach (var kvp in parameters) { @@ -87,9 +89,9 @@ namespace Squidex.Infrastructure.Log.Adapter } } - if (exception != null) + if (ctx.exception != null) { - writer.WriteException(exception); + writer.WriteException(ctx.exception); } }); } diff --git a/src/Squidex.Infrastructure/Log/IArrayWriter.cs b/src/Squidex.Infrastructure/Log/IArrayWriter.cs index d80dae6ed..bd0e02b4a 100644 --- a/src/Squidex.Infrastructure/Log/IArrayWriter.cs +++ b/src/Squidex.Infrastructure/Log/IArrayWriter.cs @@ -25,5 +25,7 @@ namespace Squidex.Infrastructure.Log IArrayWriter WriteValue(Instant value); IArrayWriter WriteObject(Action objectWriter); + + IArrayWriter WriteObject(T context, Action objectWriter); } } \ No newline at end of file diff --git a/src/Squidex.Infrastructure/Log/IObjectWriter.cs b/src/Squidex.Infrastructure/Log/IObjectWriter.cs index b1f7cbad1..98f02aed3 100644 --- a/src/Squidex.Infrastructure/Log/IObjectWriter.cs +++ b/src/Squidex.Infrastructure/Log/IObjectWriter.cs @@ -26,6 +26,10 @@ namespace Squidex.Infrastructure.Log IObjectWriter WriteObject(string property, Action objectWriter); + IObjectWriter WriteObject(string property, T context, Action objectWriter); + IObjectWriter WriteArray(string property, Action arrayWriter); + + IObjectWriter WriteArray(string property, T context, Action arrayWriter); } } diff --git a/src/Squidex.Infrastructure/Log/ISemanticLog.cs b/src/Squidex.Infrastructure/Log/ISemanticLog.cs index cf07fb5bd..2dc24197f 100644 --- a/src/Squidex.Infrastructure/Log/ISemanticLog.cs +++ b/src/Squidex.Infrastructure/Log/ISemanticLog.cs @@ -11,7 +11,7 @@ namespace Squidex.Infrastructure.Log { public interface ISemanticLog { - void Log(SemanticLogLevel logLevel, Action action); + void Log(SemanticLogLevel logLevel, T context, Action action); ISemanticLog CreateScope(Action objectWriter); } diff --git a/src/Squidex.Infrastructure/Log/JsonLogWriter.cs b/src/Squidex.Infrastructure/Log/JsonLogWriter.cs index 413dbd136..a79108169 100644 --- a/src/Squidex.Infrastructure/Log/JsonLogWriter.cs +++ b/src/Squidex.Infrastructure/Log/JsonLogWriter.cs @@ -147,6 +147,18 @@ namespace Squidex.Infrastructure.Log return this; } + IObjectWriter IObjectWriter.WriteObject(string property, T context, Action objectWriter) + { + jsonWriter.WritePropertyName(Format(property)); + jsonWriter.WriteStartObject(); + + objectWriter?.Invoke(context, this); + + jsonWriter.WriteEndObject(); + + return this; + } + IObjectWriter IObjectWriter.WriteArray(string property, Action arrayWriter) { jsonWriter.WritePropertyName(Format(property)); @@ -159,6 +171,18 @@ namespace Squidex.Infrastructure.Log return this; } + IObjectWriter IObjectWriter.WriteArray(string property, T context, Action arrayWriter) + { + jsonWriter.WritePropertyName(Format(property)); + jsonWriter.WriteStartArray(); + + arrayWriter?.Invoke(context, this); + + jsonWriter.WriteEndArray(); + + return this; + } + IArrayWriter IArrayWriter.WriteObject(Action objectWriter) { jsonWriter.WriteStartObject(); @@ -170,6 +194,17 @@ namespace Squidex.Infrastructure.Log return this; } + IArrayWriter IArrayWriter.WriteObject(T context, Action objectWriter) + { + jsonWriter.WriteStartObject(); + + objectWriter?.Invoke(context, this); + + jsonWriter.WriteEndObject(); + + return this; + } + private static string Format(string property) { if (ReferenceEquals(string.IsInterned(property), property)) diff --git a/src/Squidex.Infrastructure/Log/ProfilerSession.cs b/src/Squidex.Infrastructure/Log/ProfilerSession.cs index 9249b630e..6ecbd3d31 100644 --- a/src/Squidex.Infrastructure/Log/ProfilerSession.cs +++ b/src/Squidex.Infrastructure/Log/ProfilerSession.cs @@ -46,10 +46,10 @@ namespace Squidex.Infrastructure.Log { 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)); + p.WriteObject(kvp.Key, kvp.Value, (value, k) => k + .WriteProperty("elapsedMsTotal", value.Total) + .WriteProperty("elapsedMsAvg", value.Total / value.Count) + .WriteProperty("count", value.Count)); } }); } diff --git a/src/Squidex.Infrastructure/Log/SemanticLog.cs b/src/Squidex.Infrastructure/Log/SemanticLog.cs index 09293315d..ca3cefea7 100644 --- a/src/Squidex.Infrastructure/Log/SemanticLog.cs +++ b/src/Squidex.Infrastructure/Log/SemanticLog.cs @@ -31,12 +31,17 @@ namespace Squidex.Infrastructure.Log this.writerFactory = writerFactory; } - public void Log(SemanticLogLevel logLevel, Action action) + public void Log(SemanticLogLevel logLevel, T context, Action action) { Guard.NotNull(action, nameof(action)); - var formattedText = FormatText(logLevel, action); + var formattedText = FormatText(logLevel, context, action); + LogFormattedText(logLevel, formattedText); + } + + private void LogFormattedText(SemanticLogLevel logLevel, string formattedText) + { List exceptions = null; for (var i = 0; i < channels.Length; i++) @@ -62,7 +67,7 @@ namespace Squidex.Infrastructure.Log } } - private string FormatText(SemanticLogLevel logLevel, Action objectWriter) + private string FormatText(SemanticLogLevel logLevel, T context, Action objectWriter) { var writer = writerFactory.Create(); @@ -70,7 +75,7 @@ namespace Squidex.Infrastructure.Log { writer.WriteProperty(nameof(logLevel), logLevel.ToString()); - objectWriter(writer); + objectWriter(context, writer); for (var i = 0; i < appenders.Length; i++) { diff --git a/src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs b/src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs index 414bf298c..7c232bdf6 100644 --- a/src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs +++ b/src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs @@ -13,47 +13,92 @@ namespace Squidex.Infrastructure.Log { public static void LogTrace(this ISemanticLog log, Action objectWriter) { - log.Log(SemanticLogLevel.Trace, objectWriter); + log.Log(SemanticLogLevel.Trace, null, (_, w) => objectWriter(w)); + } + + public static void LogTrace(this ISemanticLog log, T context, Action objectWriter) + { + log.Log(SemanticLogLevel.Trace, context, objectWriter); } public static void LogDebug(this ISemanticLog log, Action objectWriter) { - log.Log(SemanticLogLevel.Debug, objectWriter); + log.Log(SemanticLogLevel.Debug, null, (_, w) => objectWriter(w)); + } + + public static void LogDebug(this ISemanticLog log, T context, Action objectWriter) + { + log.Log(SemanticLogLevel.Debug, context, objectWriter); } public static void LogInformation(this ISemanticLog log, Action objectWriter) { - log.Log(SemanticLogLevel.Information, objectWriter); + log.Log(SemanticLogLevel.Information, null, (_, w) => objectWriter(w)); + } + + public static void LogInformation(this ISemanticLog log, T context, Action objectWriter) + { + log.Log(SemanticLogLevel.Information, context, objectWriter); } public static void LogWarning(this ISemanticLog log, Action objectWriter) { - log.Log(SemanticLogLevel.Warning, objectWriter); + log.Log(SemanticLogLevel.Warning, null, (_, w) => objectWriter(w)); + } + + public static void LogWarning(this ISemanticLog log, T context, Action objectWriter) + { + log.Log(SemanticLogLevel.Warning, context, objectWriter); } public static void LogWarning(this ISemanticLog log, Exception exception, Action objectWriter = null) { - log.Log(SemanticLogLevel.Warning, writer => writer.WriteException(exception, objectWriter)); + log.Log(SemanticLogLevel.Warning, null, (_, w) => w.WriteException(exception, objectWriter)); + } + + public static void LogWarning(this ISemanticLog log, Exception exception, T context, Action objectWriter = null) + { + log.Log(SemanticLogLevel.Warning, context, (ctx, w) => w.WriteException(exception, ctx, objectWriter)); } public static void LogError(this ISemanticLog log, Action objectWriter) { - log.Log(SemanticLogLevel.Error, objectWriter); + log.Log(SemanticLogLevel.Error, null, (_, w) => objectWriter(w)); + } + + public static void LogError(this ISemanticLog log, T context, Action objectWriter) + { + log.Log(SemanticLogLevel.Error, context, objectWriter); } public static void LogError(this ISemanticLog log, Exception exception, Action objectWriter = null) { - log.Log(SemanticLogLevel.Error, writer => writer.WriteException(exception, objectWriter)); + log.Log(SemanticLogLevel.Error, null, (_, w) => w.WriteException(exception, objectWriter)); + } + + public static void LogError(this ISemanticLog log, Exception exception, T context, Action objectWriter = null) + { + log.Log(SemanticLogLevel.Error, context, (ctx, w) => w.WriteException(exception, ctx, objectWriter)); } public static void LogFatal(this ISemanticLog log, Action objectWriter) { - log.Log(SemanticLogLevel.Fatal, objectWriter); + log.Log(SemanticLogLevel.Fatal, null, (_, w) => objectWriter(w)); + } + + public static void LogFatal(this ISemanticLog log, T context, Action objectWriter) + { + log.Log(SemanticLogLevel.Fatal, context, objectWriter); } public static void LogFatal(this ISemanticLog log, Exception exception, Action objectWriter = null) { - log.Log(SemanticLogLevel.Fatal, writer => writer.WriteException(exception, objectWriter)); + log.Log(SemanticLogLevel.Fatal, null, (_, w) => w.WriteException(exception, objectWriter)); + } + + public static void LogFatal(this ISemanticLog log, Exception exception, T context, Action objectWriter = null) + { + log.Log(SemanticLogLevel.Fatal, context, (ctx, w) => w.WriteException(exception, ctx, objectWriter)); } private static void WriteException(this IObjectWriter writer, Exception exception, Action objectWriter) @@ -66,32 +111,57 @@ namespace Squidex.Infrastructure.Log } } + private static void WriteException(this IObjectWriter writer, Exception exception, T context, Action objectWriter) + { + objectWriter?.Invoke(context, writer); + + if (exception != null) + { + writer.WriteException(exception); + } + } + public static IObjectWriter WriteException(this IObjectWriter writer, Exception exception) { - return writer.WriteObject(nameof(exception), inner => + return writer.WriteObject(nameof(exception), exception, (ctx, w) => { - inner.WriteProperty("type", exception.GetType().FullName); - inner.WriteProperty("message", exception.Message); - inner.WriteProperty("stackTrace", exception.StackTrace); + w.WriteProperty("type", ctx.GetType().FullName); + w.WriteProperty("message", ctx.Message); + w.WriteProperty("stackTrace", ctx.StackTrace); }); } public static IDisposable MeasureTrace(this ISemanticLog log, Action objectWriter) { - return log.Measure(SemanticLogLevel.Trace, objectWriter); + return log.Measure(SemanticLogLevel.Trace, null, (_, w) => objectWriter(w)); + } + + public static IDisposable MeasureTrace(this ISemanticLog log, T context, Action objectWriter) + { + return log.Measure(SemanticLogLevel.Trace, context, objectWriter); } public static IDisposable MeasureDebug(this ISemanticLog log, Action objectWriter) { - return log.Measure(SemanticLogLevel.Debug, objectWriter); + return log.Measure(SemanticLogLevel.Debug, null, (_, w) => objectWriter(w)); + } + + public static IDisposable MeasureDebug(this ISemanticLog log, T context, Action objectWriter) + { + return log.Measure(SemanticLogLevel.Debug, context, objectWriter); } public static IDisposable MeasureInformation(this ISemanticLog log, Action objectWriter) { - return log.Measure(SemanticLogLevel.Information, objectWriter); + return log.Measure(SemanticLogLevel.Information, null, (_, w) => objectWriter(w)); + } + + public static IDisposable MeasureInformation(this ISemanticLog log, T context, Action objectWriter) + { + return log.Measure(SemanticLogLevel.Information, context, objectWriter); } - private static IDisposable Measure(this ISemanticLog log, SemanticLogLevel logLevel, Action objectWriter) + private static IDisposable Measure(this ISemanticLog log, SemanticLogLevel logLevel, T context, Action objectWriter) { var watch = ValueStopwatch.StartNew(); @@ -99,11 +169,11 @@ namespace Squidex.Infrastructure.Log { var elapsedMs = watch.Stop(); - log.Log(logLevel, writer => + log.Log(logLevel, (Context: context, elapsedMs), (ctx, w) => { - objectWriter?.Invoke(writer); + objectWriter?.Invoke(ctx.Context, w); - writer.WriteProperty("elapsedMs", elapsedMs); + w.WriteProperty("elapsedMs", elapsedMs); }); }); } diff --git a/src/Squidex/Areas/Api/Controllers/Contents/ContentsController.cs b/src/Squidex/Areas/Api/Controllers/Contents/ContentsController.cs index ffed1ed06..4ea013deb 100644 --- a/src/Squidex/Areas/Api/Controllers/Contents/ContentsController.cs +++ b/src/Squidex/Areas/Api/Controllers/Contents/ContentsController.cs @@ -123,7 +123,7 @@ namespace Squidex.Areas.Api.Controllers.Contents [HttpGet] [Route("content/{app}/{name}/")] [ApiPermission] - [ApiCosts(2)] + [ApiCosts(1)] public async Task GetContents(string app, string name, [FromQuery] bool archived = false, [FromQuery] string ids = null) { var context = Context().WithArchived(archived); diff --git a/src/Squidex/Areas/IdentityServer/Controllers/Account/AccountController.cs b/src/Squidex/Areas/IdentityServer/Controllers/Account/AccountController.cs index ae9abfe5a..a7da10ccb 100644 --- a/src/Squidex/Areas/IdentityServer/Controllers/Account/AccountController.cs +++ b/src/Squidex/Areas/IdentityServer/Controllers/Account/AccountController.cs @@ -386,18 +386,20 @@ namespace Squidex.Areas.IdentityServer.Controllers.Account errorMessageBuilder.AppendLine(error.Description); } - log.LogError(w => w - .WriteProperty("action", operationName) + var errorMessage = errorMessageBuilder.ToString(); + + log.LogError((operationName, errorMessage), (ctx, w) => w + .WriteProperty("action", ctx.operationName) .WriteProperty("status", "Failed") - .WriteProperty("message", errorMessageBuilder.ToString())); + .WriteProperty("message", ctx.errorMessage)); } return result.Succeeded; } catch (Exception ex) { - log.LogError(ex, w => w - .WriteProperty("action", operationName) + log.LogError(ex, operationName, (logOperationName, w) => w + .WriteProperty("action", logOperationName) .WriteProperty("status", "Failed")); return false; diff --git a/src/Squidex/Config/Authentication/GithubHandler.cs b/src/Squidex/Config/Authentication/GithubHandler.cs index 51da9a986..62cba51ce 100644 --- a/src/Squidex/Config/Authentication/GithubHandler.cs +++ b/src/Squidex/Config/Authentication/GithubHandler.cs @@ -6,11 +6,8 @@ // ========================================================================== using System.Security.Claims; -using System.Text.Encodings.Web; using System.Threading.Tasks; -using Microsoft.AspNetCore.Authentication; using Microsoft.AspNetCore.Authentication.OAuth; -using Microsoft.Extensions.Options; using Squidex.Infrastructure; using Squidex.Shared.Identity; diff --git a/src/Squidex/Config/Domain/LoggingExtensions.cs b/src/Squidex/Config/Domain/LoggingExtensions.cs index 1c1526682..c11379044 100644 --- a/src/Squidex/Config/Domain/LoggingExtensions.cs +++ b/src/Squidex/Config/Domain/LoggingExtensions.cs @@ -30,11 +30,11 @@ namespace Squidex.Config.Domain var orderedConfigs = config.AsEnumerable().Where(kvp => kvp.Value != null).OrderBy(x => x.Key, StringComparer.OrdinalIgnoreCase); - foreach (var kvp in orderedConfigs) + foreach (var (key, val) in orderedConfigs) { - if (logged.Add(kvp.Key)) + if (logged.Add(key)) { - c.WriteProperty(kvp.Key.ToLowerInvariant(), kvp.Value); + c.WriteProperty(key.ToLowerInvariant(), val); } } })); diff --git a/src/Squidex/Pipeline/ActionContextLogAppender.cs b/src/Squidex/Pipeline/ActionContextLogAppender.cs index b07972140..97c6060b3 100644 --- a/src/Squidex/Pipeline/ActionContextLogAppender.cs +++ b/src/Squidex/Pipeline/ActionContextLogAppender.cs @@ -34,7 +34,7 @@ namespace Squidex.Pipeline Guid requestId; - if (httpContext.Items.TryGetValue(nameof(requestId), out var value) && value is Guid requestIdValue) + if (httpContext.Items.TryGetValue(nameof(requestId), out var requestIdvalue) && requestIdvalue is Guid requestIdValue) { requestId = requestIdValue; } @@ -43,21 +43,23 @@ namespace Squidex.Pipeline httpContext.Items[nameof(requestId)] = requestId = Guid.NewGuid(); } - writer.WriteObject("web", w => + var logContext = (requestId, context: httpContext, actionContextAccessor); + + writer.WriteObject("web", logContext, (ctx, w) => { - w.WriteProperty("requestId", requestId.ToString()); - w.WriteProperty("requestPath", httpContext.Request.Path); - w.WriteProperty("requestMethod", httpContext.Request.Method); + w.WriteProperty("requestId", ctx.requestId.ToString()); + w.WriteProperty("requestPath", ctx.context.Request.Path); + w.WriteProperty("requestMethod", ctx.context.Request.Method); - var actionContext = actionContextAccessor.ActionContext; + var actionContext = ctx.actionContextAccessor.ActionContext; if (actionContext != null) { - w.WriteObject("routeValues", r => + w.WriteObject("routeValues", actionContext.ActionDescriptor.RouteValues, (routeValues, r) => { - foreach (var kvp in actionContext.ActionDescriptor.RouteValues) + foreach (var (key, val) in routeValues) { - r.WriteProperty(kvp.Key, kvp.Value); + r.WriteProperty(key, val); } }); } diff --git a/src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs b/src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs index 19e706467..4dd0467a4 100644 --- a/src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs +++ b/src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs @@ -9,6 +9,7 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Http; using Squidex.Infrastructure; using Squidex.Infrastructure.Log; +using Squidex.Infrastructure.Security; namespace Squidex.Pipeline { @@ -35,11 +36,36 @@ namespace Squidex.Pipeline { var elapsedMs = watch.Stop(); - log.LogInformation(w => + log.LogInformation((elapsedMs, context), (ctx, w) => { Profiler.Session?.Write(w); - w.WriteProperty("elapsedRequestMs", elapsedMs); + w.WriteObject("ctx", ctx.context, (innerHttpContext, c) => + { + var app = innerHttpContext.Features.Get()?.App; + + if (app != null) + { + c.WriteProperty("appId", app.Id.ToString()); + c.WriteProperty("appName", app.Name); + } + + var subjectId = innerHttpContext.User.OpenIdSubject(); + + if (!string.IsNullOrWhiteSpace(subjectId)) + { + c.WriteProperty("userId", subjectId); + } + + var clientId = innerHttpContext.User.OpenIdClientId(); + + if (!string.IsNullOrWhiteSpace(subjectId)) + { + c.WriteProperty("clientId", subjectId); + } + }); + + w.WriteProperty("elapsedRequestMs", ctx.elapsedMs); }); } } diff --git a/tests/Squidex.Infrastructure.Tests/Commands/LogCommandMiddlewareTests.cs b/tests/Squidex.Infrastructure.Tests/Commands/LogCommandMiddlewareTests.cs index 716aaf60f..0c090f0fd 100644 --- a/tests/Squidex.Infrastructure.Tests/Commands/LogCommandMiddlewareTests.cs +++ b/tests/Squidex.Infrastructure.Tests/Commands/LogCommandMiddlewareTests.cs @@ -28,7 +28,7 @@ namespace Squidex.Infrastructure.Commands public Dictionary LogLevels { get; } = new Dictionary(); - public void Log(SemanticLogLevel logLevel, Action action) + public void Log(SemanticLogLevel logLevel, T context, Action action) { LogCount++; LogLevels[logLevel] = LogLevels.GetOrDefault(logLevel) + 1; diff --git a/tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs b/tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs index 5d3b00d6c..c8ff22a92 100644 --- a/tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs +++ b/tests/Squidex.Infrastructure.Tests/Log/JsonLogWriterTests.cs @@ -114,6 +114,22 @@ namespace Squidex.Infrastructure.Log Assert.Equal(@"{""property1"":[{""property2"":120}]}", result); } + [Fact] + public void Should_write_object_in_array_with_context() + { + var result = sut.WriteArray("property1", a => a.WriteObject(13, (ctx, b) => b.WriteProperty("property2", 13))).ToString(); + + Assert.Equal(@"{""property1"":[{""property2"":13}]}", result); + } + + [Fact] + public void Should_write_array_value_with_context() + { + var result = sut.WriteArray("property", 13, (ctx, a) => a.WriteValue(ctx)).ToString(); + + Assert.Equal(@"{""property"":[13]}", result); + } + [Fact] public void Should_write_date_value() { @@ -127,11 +143,19 @@ namespace Squidex.Infrastructure.Log [Fact] public void Should_write_nested_object() { - var result = sut.WriteObject("property", a => a.WriteProperty("nested", "my-string")).ToString(); + var result = sut.WriteObject("property", o => o.WriteProperty("nested", "my-string")).ToString(); Assert.Equal(@"{""property"":{""nested"":""my-string""}}", result); } + [Fact] + public void Should_write_nested_object_with_context() + { + var result = sut.WriteObject("property", 13, (ctx, o) => o.WriteProperty("nested", ctx)).ToString(); + + Assert.Equal(@"{""property"":{""nested"":13}}", result); + } + [Fact] public void Should_write_pretty_json() { diff --git a/tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs b/tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs index cd5685739..fd4b8566d 100644 --- a/tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs +++ b/tests/Squidex.Infrastructure.Tests/Log/SemanticLogTests.cs @@ -45,8 +45,8 @@ namespace Squidex.Infrastructure.Log [Fact] public void Should_log_multiple_lines() { - Log.Log(SemanticLogLevel.Error, w => w.WriteProperty("logMessage", "Msg1")); - Log.Log(SemanticLogLevel.Error, w => w.WriteProperty("logMessage", "Msg2")); + Log.Log(SemanticLogLevel.Error, null, (_, w) => w.WriteProperty("logMessage", "Msg1")); + Log.Log(SemanticLogLevel.Error, null, (_, w) => w.WriteProperty("logMessage", "Msg2")); var expected1 = LogTest(w => w @@ -129,6 +129,19 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_trace_and_context() + { + Log.LogTrace(1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Trace") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_debug() { @@ -142,6 +155,19 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_debug_and_context() + { + Log.LogDebug(1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Debug") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_information() { @@ -155,6 +181,19 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_information_and_context() + { + Log.LogInformation(1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Information") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_warning() { @@ -168,6 +207,19 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_warning_and_context() + { + Log.LogWarning(1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Warning") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_warning_exception() { @@ -183,6 +235,22 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_warning_exception_and_context() + { + var exception = new InvalidOperationException(); + + Log.LogWarning(exception, 1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Warning") + .WriteProperty("logValue", 1500) + .WriteException(exception)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_error() { @@ -196,6 +264,19 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_error_and_context() + { + Log.LogError(1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Error") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_error_exception() { @@ -211,6 +292,22 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_error_exception_and_context() + { + var exception = new InvalidOperationException(); + + Log.LogError(exception, 1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Error") + .WriteProperty("logValue", 1500) + .WriteException(exception)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_fatal() { @@ -224,6 +321,19 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_fatal_and_context() + { + Log.LogFatal(1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Fatal") + .WriteProperty("logValue", 1500)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_with_fatal_exception() { @@ -239,6 +349,22 @@ namespace Squidex.Infrastructure.Log Assert.Equal(expected, output); } + [Fact] + public void Should_log_with_fatal_exception_and_context() + { + var exception = new InvalidOperationException(); + + Log.LogFatal(exception, 1500, (ctx, w) => w.WriteProperty("logValue", ctx)); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Fatal") + .WriteProperty("logValue", 1500) + .WriteException(exception)); + + Assert.Equal(expected, output); + } + [Fact] public void Should_log_nothing_when_exception_is_null() { @@ -265,6 +391,20 @@ namespace Squidex.Infrastructure.Log Assert.StartsWith(expected.Substring(0, 55), output, StringComparison.Ordinal); } + [Fact] + public void Should_measure_trace_with_contex() + { + Log.MeasureTrace("My Message", (ctx, w) => w.WriteProperty("message", ctx)).Dispose(); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Trace") + .WriteProperty("message", "My Message") + .WriteProperty("elapsedMs", 0)); + + Assert.StartsWith(expected.Substring(0, 55), output, StringComparison.Ordinal); + } + [Fact] public void Should_measure_debug() { @@ -279,6 +419,20 @@ namespace Squidex.Infrastructure.Log Assert.StartsWith(expected.Substring(0, 55), output, StringComparison.Ordinal); } + [Fact] + public void Should_measure_debug_with_contex() + { + Log.MeasureDebug("My Message", (ctx, w) => w.WriteProperty("message", ctx)).Dispose(); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Debug") + .WriteProperty("message", "My Message") + .WriteProperty("elapsedMs", 0)); + + Assert.StartsWith(expected.Substring(0, 55), output, StringComparison.Ordinal); + } + [Fact] public void Should_measure_information() { @@ -293,6 +447,20 @@ namespace Squidex.Infrastructure.Log Assert.StartsWith(expected.Substring(0, 55), output, StringComparison.Ordinal); } + [Fact] + public void Should_measure_information_with_contex() + { + Log.MeasureInformation("My Message", (ctx, w) => w.WriteProperty("message", ctx)).Dispose(); + + var expected = + LogTest(w => w + .WriteProperty("logLevel", "Information") + .WriteProperty("message", "My Message") + .WriteProperty("elapsedMs", 0)); + + Assert.StartsWith(expected.Substring(0, 55), output, StringComparison.Ordinal); + } + [Fact] public void Should_log_with_extensions_logger() { @@ -334,7 +502,7 @@ namespace Squidex.Infrastructure.Log try { - sut.Log(SemanticLogLevel.Debug, w => w.WriteProperty("should", "throw")); + sut.Log(SemanticLogLevel.Debug, null, (_, w) => w.WriteProperty("should", "throw")); Assert.False(true); }