public async Task Invoke(HttpContext context)
{
using (LogContext.Push(new SerilogHttpContextEnricher(_accessor)))
{
await _next(context);
}
}
public async Task WrapIncludesOriginalContextAsync()
{
try
{
try
{
await Task.Delay(1);
using (LogContext.Push(new PropertyEnricher("A", 1)))
throw new FormatException();
}
catch (Exception ex)
{
await Task.Delay(1);
using (LogContext.Push(new PropertyEnricher("B", 2)))
throw new ApplicationException("Wrapper", ex);
}
}
catch (ApplicationException ex)
{
await Task.Delay(1);
using (LogContext.Push(new ThrowContextEnricher()))
_log.Information(ex, "Unit test");
}
Assert.Equal(1, _lastEvent.Properties["A"].LiteralValue());
Assert.Equal(2, _lastEvent.Properties["B"].LiteralValue());
}
private static IDisposable CreateLogContextForException(TRequest request, Stopwatch sw)
{
return(LogContext.Push(new PropertyEnricher("ExecutionTimeMs", sw.ElapsedMilliseconds),
new PropertyEnricher("Command", request),
new PropertyEnricher("Outcome", "Exception")
));
}
public async Task InvokeAsync(HttpContext context, RequestDelegate next)
{
using (LogContext.Push(_httpContextEnricher.WithHttpContext(context)))
{
await next(context);
}
}
public async Task ReThrowCapturesPropertyAsync()
{
try
{
try
{
await Task.Delay(1);
using (LogContext.Push(new PropertyEnricher("A", 1)))
throw new ApplicationException();
}
catch
{
await Task.Delay(1);
using (LogContext.Push(new PropertyEnricher("B", 2)))
throw;
}
}
catch (ApplicationException ex)
{
await Task.Delay(1);
using (LogContext.Push(new ThrowContextEnricher()))
_log.Information(ex, "Unit test");
}
Assert.Equal(1, _lastEvent.Properties["A"].LiteralValue());
Assert.Equal(2, _lastEvent.Properties["B"].LiteralValue());
}
public async Task <Unit> Handle(T command, CancellationToken cancellationToken)
{
if (command is IRecurringCommand)
{
return(await _decorated.Handle(command, cancellationToken));
}
using (
LogContext.Push(
new RequestLogEnricher(_executionContextAccessor),
new CommandLogEnricher(command)))
{
try
{
this._logger.Information(
"Executing command {Command}",
command.GetType().Name);
var result = await _decorated.Handle(command, cancellationToken);
this._logger.Information("Command {Command} processed successful", command.GetType().Name);
return(result);
}
catch (Exception exception)
{
this._logger.Error(exception, "Command {Command} processing failed", command.GetType().Name);
throw;
}
}
}
public void MultipleNestedPropertiesOverrideLessNestedOnes()
{
LogEvent?lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
using (LogContext.Push(new PropertyEnricher("A1", 1), new PropertyEnricher("A2", 2)))
{
log.Write(Some.InformationEvent());
Assert.NotNull(lastEvent);
Assert.Equal(1, lastEvent !.Properties["A1"].LiteralValue());
Assert.Equal(2, lastEvent.Properties["A2"].LiteralValue());
using (LogContext.Push(new PropertyEnricher("A1", 10), new PropertyEnricher("A2", 20)))
{
log.Write(Some.InformationEvent());
Assert.Equal(10, lastEvent.Properties["A1"].LiteralValue());
Assert.Equal(20, lastEvent.Properties["A2"].LiteralValue());
}
log.Write(Some.InformationEvent());
Assert.Equal(1, lastEvent.Properties["A1"].LiteralValue());
Assert.Equal(2, lastEvent.Properties["A2"].LiteralValue());
}
log.Write(Some.InformationEvent());
Assert.False(lastEvent.Properties.ContainsKey("A1"));
Assert.False(lastEvent.Properties.ContainsKey("A2"));
}
public async Task InvokeAsync(HttpContext context, RequestDelegate next)
{
var enrichers = new List <ILogEventEnricher>();
if (_currentTenant?.Id != null)
{
enrichers.Add(new PropertyEnricher(_options.EnricherPropertyNames.TenantId, _currentTenant.Id));
}
if (_currentUser?.Id != null)
{
enrichers.Add(new PropertyEnricher(_options.EnricherPropertyNames.UserId, _currentUser.Id));
}
if (_currentClient?.Id != null)
{
enrichers.Add(new PropertyEnricher(_options.EnricherPropertyNames.ClientId, _currentClient.Id));
}
var correlationId = _correlationIdProvider.Get();
if (!string.IsNullOrEmpty(correlationId))
{
enrichers.Add(new PropertyEnricher(_options.EnricherPropertyNames.CorrelationId, correlationId));
}
using (LogContext.Push(enrichers.ToArray()))
{
await next(context).ConfigureAwait(false);
}
}
public static void ConfigureServices(IServiceCollection services)
{
services.AddScopedLoggingContext(
(n, v) => LogContext.PushProperty(n, v),
v => LogContext.Push(v.Select(x => (ILogEventEnricher) new PropertyEnricher(x.Key, x.Value)).ToArray())
);
services.AddSingleton <IConfiguration>(Configuration);
//services.AddElastic();
var settings = Configuration.GetSection("ElasticSettings");
services.AddElastic <POFineLineOutput>(options =>
{
options.NodeList = settings.GetSection("NodeList").Get <string[]>();
options.UserName = settings["UserName"];
options.Password = settings["Password"];
}, p => p.PurchaseOrder);
//get the output options
services.Configure <OutputSettings>(Configuration.GetSection("WriteOutput"));
services.AddTransient <ElasticWriter>();
services.AddTransient <ProduceOutput>();
services.AddSingleton <App>();
}
public async Task <TResult> Handle(T command, CancellationToken cancellationToken)
{
using (
LogContext.Push(
new RequestLogEnricher(_executionContextAccessor),
new CommandLogEnricher(command)))
{
try
{
this._logger.Information(
"Executing command {@Command}",
command);
var result = await _decorated.Handle(command, cancellationToken);
this._logger.Information("Command processed successful, result {Result}", result);
return(result);
}
catch (Exception exception)
{
this._logger.Error(exception, "Command processing failed");
throw;
}
}
}
public async Task Invoke(HttpContext context, ILogEventEnricher logEventEnricher)
{
using (LogContext.Push(logEventEnricher))
{
await _next(context);
}
}
public void ClonedLogContextCanSharedAcrossThreads()
{
LogEvent?lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
ILogEventEnricher clonedContext;
using (LogContext.PushProperty("A", 1))
{
clonedContext = LogContext.Clone();
}
var t = new Thread(() =>
{
using (LogContext.Push(clonedContext))
{
log.Write(Some.InformationEvent());
}
});
t.Start();
t.Join();
Assert.NotNull(lastEvent);
Assert.Equal(1, lastEvent !.Properties["A"].LiteralValue());
}
private static void Example3()
{
Log.Logger = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Console(new RenderedCompactJsonFormatter())
.CreateLogger();
ThrowContextEnricher.EnsureInitialized();
using (LogContext.PushProperty("A", "outer"))
try
{
using (LogContext.PushProperty("A", "inner"))
{
throw new Exception();
}
}
catch (Exception ex)
{
using (LogContext.Push(new ThrowContextEnricher()))
{
Log.Error(ex, "Value of A is {A}");
}
}
}
private void LogMethodAfterInvocation(IInvocation invocation, LogActive activeState, object returnValue)
{
if (invocation == null)
{
throw new ArgumentNullException(nameof(invocation));
}
LogActive methodActiveState = activeState;
MethodInfo methodInfo = invocation.MethodInvocationTarget;
Debug.Assert(methodInfo != null);
(object filteredReturnValue, LogActive anyParametersToLog) = FilterReturnValue(methodInfo, methodActiveState, returnValue);
if (anyParametersToLog == LogActive.On)
{
using (LogContext.PushProperty(LogTypeName, LogType.Diagnostic))
using (LogContext.Push(new InvocationEnricher(invocation)))
using (LogContext.PushProperty(ReturnValueName, filteredReturnValue, destructureObjects: true))
{
string logMessage = $"{GetSourceMessage(invocation)} invocation ended";
m_Logger.Information(logMessage);
}
}
}
public static void Main(string[] args)
{
Console.Title = "SG.PO.Intertek.Ingester";
var config = DefaultConfiguration();
var logging = DefaultLogging(config);
var ingester = new SGIngester(config, logging);
var loggingContext = new LogContextWrapper(
(n, v) => LogContext.PushProperty(n, v),
v => LogContext.Push(v.Select(x => (ILogEventEnricher) new PropertyEnricher(x.Key, x.Value)).ToArray())
);
Log.Logger.Information("Service Start");
try
{
ingester.Run(loggingContext);
}
catch (Exception ex)
{
Log.Logger.Fatal("{Unhandled exception}", ex);
throw ex;
}
finally
{
Log.CloseAndFlush();
}
}
// Must inject IUserProvider here as it is scoped
public async Task Invoke(HttpContext httpContext, IUserProvider userProvider)
{
var sw = Stopwatch.StartNew();
// Add ASPNET trace ID as a property on all logged messages
using (LogContext.PushProperty("TraceID", httpContext.TraceIdentifier))
using (LogContext.Push(new UserLogEnricher(userProvider)))
{
try
{
await _next(httpContext);
sw.Stop();
int?statusCode = httpContext.Response?.StatusCode;
var level = statusCode >= 500 ? LogEventLevel.Error
: statusCode >= 400 ? LogEventLevel.Warning
: LogEventLevel.Debug;
_logger.Write(level, _messageTemplate, httpContext.Request.Method, httpContext.Request.Path, httpContext.Request.QueryString, httpContext.Connection.RemoteIpAddress, statusCode, sw.Elapsed.TotalMilliseconds);
}
catch (Exception ex)
{
sw.Stop();
_logger.Error(nameof(RequestLogger), ex);
}
}
}
public static void ConfigureServices(IServiceCollection services)
{
services.AddScopedLoggingContext(
(n, v) => LogContext.PushProperty(n, v),
v => LogContext.Push(v.Select(x => (ILogEventEnricher) new PropertyEnricher(x.Key, x.Value)).ToArray())
);
services.AddSingleton <IConfiguration>(Configuration);
//services.AddElastic();
var settings = Configuration.GetSection("ElasticSettings");
services.AddElastic <DataModels.Outputmodels.POChinoOutput>(options =>
{
options.NodeList = settings.GetSection("NodeList").Get <string[]>();
options.UserName = settings["UserName"];
options.Password = settings["Password"];
}, p => p.OrderId);
//get the output options
services.Configure <OutputSettings>(Configuration.GetSection("WriteOutput"));
services.Configure <Header>(Configuration.GetSection("ChinoOutputHeaderSettings"));
services.Configure <Order>(Configuration.GetSection("ChinoOrderSettings"));
services.Configure <POChinoLineItemQuantity>(Configuration.GetSection("LineItemSettings"));
services.AddTransient <ElasticWriter>();
services.AddTransient <POChinoUtilities>();
services.AddSingleton <App>();
}
protected override async Task <TResult> InterceptAsync <TResult>(
IInvocation invocation,
Func <IInvocation, Task <TResult> > proceed)
{
if (invocation == null)
{
throw new ArgumentNullException(nameof(invocation));
}
if (proceed == null)
{
throw new ArgumentNullException(nameof(proceed));
}
using (LogContext.PushProperty(LogTypesName, LogTypes.Invocation))
using (LogContext.Push(new InvocationEnricher(invocation)))
{
m_Logger.Information($"{GetSourceMessage(invocation)} started");
}
var result = await proceed(invocation).ConfigureAwait(false);
using (LogContext.PushProperty(LogTypesName, LogTypes.Invocation))
using (LogContext.Push(new InvocationEnricher(invocation)))
{
m_Logger.Information($"{GetSourceMessage(invocation)} ended");
}
return(result);
}
public async Task InvokeAsync(HttpContext context)
{
using (LogContext.Push(CreateEnrichers(context)))
{
await _next.Invoke(context);
}
}
public async Task <ISet <int> > Search(SearchRequest request)
{
var timeout = new CancellationTokenSource(TimeSpan.FromSeconds(15));
var timer = Stopwatch.StartNew();
using (LogContext.Push(new SearchEnricher(request)))
{
_logger.Information("Starting search {SearchId}", request.SearchId);
var tasks = _suppliers
.Select(s => s.GetAvailability(request.EstabIds, timeout.Token))
.ToList();
await Task.WhenAll(tasks);
var results = new HashSet <int>(tasks
.Where(t => t?.Result?.EstabIds != null)
.SelectMany(t => t.Result.EstabIds));
_logger.Information(
"Search completed in {Elapsed:0.00}ms. {ResultCount} result(s) found",
timer.Elapsed.TotalMilliseconds,
results.Count);
return(results);
}
}
public async Task ContextEnrichersInAsyncScopeCanBeCleared()
{
LogEvent?lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
using (LogContext.Push(new PropertyEnricher("A", 1)))
{
await Task.Run(() =>
{
LogContext.Reset();
log.Write(Some.InformationEvent());
});
Assert.NotNull(lastEvent);
Assert.Empty(lastEvent !.Properties);
// Reset should only work for current async scope, outside of it previous Context
// instance should be available again.
log.Write(Some.InformationEvent());
Assert.Equal(1, lastEvent.Properties["A"].LiteralValue());
}
}
private static void LinkEnrichersToContext(TraceIdentifiersContext context, LogContextBuilder builder)
{
TraceIdentifiersEnricher traceIdentifiersEnricher = new TraceIdentifiersEnricher(context, builder);
IDisposable disposable = LogContext.Push(traceIdentifiersEnricher);
context.Link(disposable);
}
public async Task ContextEnrichersCanBeTemporarilyCleared()
{
LogEvent?lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
using (LogContext.Push(new PropertyEnricher("A", 1)))
{
using (LogContext.Suspend())
{
await Task.Run(() =>
{
log.Write(Some.InformationEvent());
});
Assert.NotNull(lastEvent);
Assert.Empty(lastEvent !.Properties);
}
// Suspend should only work for scope of using. After calling Dispose all enrichers
// should be restored.
log.Write(Some.InformationEvent());
Assert.Equal(1, lastEvent.Properties["A"].LiteralValue());
}
}
public void ReThrowDoesNotOverrideOriginalProperty(bool preserveStack)
{
try
{
try
{
using (LogContext.Push(new PropertyEnricher("A", 1)))
throw new ApplicationException();
}
catch (Exception ex)
{
using (LogContext.Push(new PropertyEnricher("A", 2)))
if (preserveStack)
{
throw;
}
else
{
throw ex;
}
}
}
catch (ApplicationException ex)
{
using (LogContext.Push(new ThrowContextEnricher()))
_log.Information(ex, "Unit test");
}
Assert.Equal(1, _lastEvent.Properties["A"].LiteralValue());
}
public async Task InvokeAsync(HttpContext context)
{
using var reader = new StreamReader(context.Request.Body);
var bodyString = await reader.ReadToEndAsync();
if (string.IsNullOrEmpty(bodyString))
{
return;
}
var logMessage = OwnIdSerializer.Deserialize <LogMessage>(bodyString);
using (LogContext.Push(new PropertyEnricher("source", logMessage.Source ?? "client-side")))
using (LogContext.Push(new PropertyEnricher("version", logMessage.Version)))
{
if (!Enum.TryParse(logMessage.LogLevel, true, out LogLevel logLevel))
{
logLevel = LogLevel.Debug;
}
using (_logger.BeginScope($"context: {context}", logMessage.Context))
{
_logger.LogWithData(logLevel, logMessage.Message, logMessage.Data);
}
}
}
public async Task InvokeAsync(HttpContext context, ICorrelationIdAccessor correlationIdAccessor)
{
using (LogContext.Push(new CorrelationIdEnricher(correlationIdAccessor)))
{
await _next(context);
}
}
public async Task Invoke(HttpContext context)
{
if (context == null)
{
throw new ArgumentNullException(nameof(context));
}
var startTime = DateTime.UtcNow;
var sw = new Stopwatch();
sw.Start();
try
{
await _next(context);
var elapsedMs = sw.ElapsedMilliseconds;
var statusCode = context.Response?.StatusCode;
var level = statusCode >= 500 ? LogEventLevel.Error : LogEventLevel.Information;
using (LogContext.Push(new W3CRequestEnricher(context, startTime, elapsedMs, _settings)))
{
var log = level == LogEventLevel.Error ? LogForErrorContext(context) : Log;
log.Write(level, MessageTemplate, context.Request.Method, context.Request.Path, statusCode, elapsedMs);
}
}
// Never caught, because `LogException()` returns false.
catch (Exception ex) when(LogException(context, sw.ElapsedMilliseconds, ex))
{
}
}
public IDisposable CreateLogContext(params PropertyPair[] propertyPairs)
{
return(LogContext.Push(
propertyPairs
.Select(pp => new PropertyEnricher(pp.Name, pp.Value))
.ToArray()));
}
public async Task Invoke(HttpContext context)
{
using (LogContext.Push(
new RequestLogEnricher(_executionContextAccessor)))
{
context.Request.Headers.TryGetValue("Content-Type", out var contentType);
_logger.Verbose("Processing request {@Path} with content type {@ContentType} and method {@Method}", context.Request.Path.Value,
contentType, context.Request.Method);
try
{
await _next(context);
}
catch (Exception exception)
when(exception is not InvalidCommandException &&
exception is not BusinessRuleValidationException &&
exception is not UnauthorizedException)
{
_logger.Error(exception, "Unexpected exception");
throw;
}
finally
{
_logger.Verbose("Processed request {@Path} with status code {@StatusCode}", context.Request.Path.Value,
context.Response.StatusCode);
}
}
}
public async Task Consume(ConsumeContext <IDownloadPackage> context)
{
var conversationEnricher = new PropertyEnricher(nameof(context.ConversationId), context.ConversationId);
var archiveRecordIdEnricher = new PropertyEnricher(nameof(context.Message.ArchiveRecordId), context.Message.ArchiveRecordId);
var packageIdEnricher = new PropertyEnricher(nameof(context.Message.PackageId), context.Message.PackageId);
using (LogContext.Push(conversationEnricher, archiveRecordIdEnricher, packageIdEnricher))
{
Log.Information("Received {CommandName} command with conversationId {ConversationId} from the bus", nameof(IDownloadPackage),
context.ConversationId);
// Get the package from the repository
// We are not waiting for it to end, because we want to free the consumer as early as possible
var packageId = context.Message.PackageId;
var archiveRecordId = context.Message.ArchiveRecordId;
var result = await repositoryManager.GetPackage(packageId, archiveRecordId, context.Message.PrimaerdatenAuftragId);
// Do we have a valid package?
if (result.Success && result.Valid)
{
// Forward the downloaded package to the asset manager for transformation
var endpoint = await context.GetSendEndpoint(new Uri(bus.Address, BusConstants.AssetManagerPrepareForTransformation));
await endpoint.Send(new PrepareForTransformationMessage
{
AssetType = AssetType.Gebrauchskopie,
CallerId = context.Message.CallerId,
RetentionCategory = context.Message.RetentionCategory,
Recipient = context.Message.Recipient,
Language = context.Message.Language,
ProtectWithPassword = context.Message.RetentionCategory != CacheRetentionCategory.UsageCopyPublic,
PrimaerdatenAuftragId = context.Message.PrimaerdatenAuftragId,
RepositoryPackage = result.PackageDetails
});
// also publish the event, that the package is downloaded
await context.Publish <IPackageDownloaded>(
new
{
PackageInfo = result
});
}
else
{
// Publish the download asset failure event
await context.Publish <IAssetReady>(new AssetReady
{
Valid = false,
ErrorMessage = result.ErrorMessage,
AssetType = AssetType.Gebrauchskopie,
CallerId = context.Message.CallerId,
ArchiveRecordId = context.Message.ArchiveRecordId,
RetentionCategory = context.Message.RetentionCategory,
Recipient = context.Message.Recipient,
PrimaerdatenAuftragId = context.Message.PrimaerdatenAuftragId
});
}
}
}