public void MoreNestedPropertiesOverrideLessNestedOnes()
{
LogEvent lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
using (LogContext.PushProperty("A", 1))
{
log.Write(Some.InformationEvent());
Assert.AreEqual(1, lastEvent.Properties["A"].LiteralValue());
using (LogContext.PushProperty("A", 2))
{
log.Write(Some.InformationEvent());
Assert.AreEqual(2, lastEvent.Properties["A"].LiteralValue());
}
log.Write(Some.InformationEvent());
Assert.AreEqual(1, lastEvent.Properties["A"].LiteralValue());
}
log.Write(Some.InformationEvent());
Assert.IsFalse(lastEvent.Properties.ContainsKey("A"));
}
public void WhenTheDateChangesTheCorrectFileIsWritten()
{
var e1 = Some.InformationEvent();
var e2 = new LogEvent(e1.Timestamp.AddDays(1), LogEventLevel.Information, null, Some.MessageTemplate(), new LogEventProperty[0]);
TestRollingEventSequence(e1, e2);
}
public async Task ContextPropertiesPersistWhenCrossAppDomainCallsAreEnabled()
{
LogEvent lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
LogContext.PermitCrossAppDomainCalls = true;
using (LogContext.PushProperty("A", 1))
{
var pre = Thread.CurrentThread.ManagedThreadId;
await Task.Delay(1000);
var post = Thread.CurrentThread.ManagedThreadId;
log.Write(Some.InformationEvent());
Assert.AreEqual(1, lastEvent.Properties["A"].LiteralValue());
// No problem if this happens occasionally.
if (pre == post)
{
Assert.Inconclusive("The test was marshalled back to the same thread after awaiting");
}
}
}
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.Equal(1, lastEvent.Properties["A"].LiteralValue());
}
public async Task RespectLogEventLimitBytes()
{
// Arrange
var testId = $"RespectLogEventLimitBytes_{Guid.NewGuid()}";
var period = TimeSpan.FromMilliseconds(1);
using var sink = new TimeRolledDurableHttpSink(
requestUri: webServerFixture.RequestUri(testId),
bufferBaseFileName: Path.Combine("logs", testId),
bufferRollingInterval: BufferRollingInterval.Day,
bufferFileSizeLimitBytes: null,
bufferFileShared: false,
retainedBufferFileCountLimit: null,
logEventLimitBytes: 1, // Is lower than emitted log event
logEventsInBatchLimit: 1000,
batchSizeLimitBytes: null,
period: period,
textFormatter: new NormalTextFormatter(),
batchFormatter: new ArrayBatchFormatter(),
httpClient: new JsonHttpClient(webServerFixture.CreateClient()));
// Act
sink.Emit(Some.InformationEvent());
await Task.Delay(10_000 * period);
// Assert
webServerFixture.GetAllBatches(testId).ShouldBeEmpty();
webServerFixture.GetAllEvents(testId).ShouldBeEmpty();
}
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.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());
}
}
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.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 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.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 ContextPropertiesCrossAsyncCalls()
{
LogEvent lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
using (LogContext.PushProperty("A", 1))
{
var pre = Thread.CurrentThread.ManagedThreadId;
await Task.Delay(1000);
var post = Thread.CurrentThread.ManagedThreadId;
log.Write(Some.InformationEvent());
Assert.Equal(1, lastEvent.Properties["A"].LiteralValue());
// No problem if this happens occasionally; was Assert.Inconclusive().
// The test was marshalled back to the same thread after awaiting.
Assert.NotSame(pre, post);
}
}
public async Task ContextPropertiesCrossAsyncCalls()
{
await TestWithSyncContext(async() =>
{
LogEvent lastEvent = null;
var log = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.Sink(new DelegatingSink(e => lastEvent = e))
.CreateLogger();
using (LogContext.PushProperty("A", 1))
{
var pre = Thread.CurrentThread.ManagedThreadId;
await Task.Yield();
var post = Thread.CurrentThread.ManagedThreadId;
log.Write(Some.InformationEvent());
Assert.Equal(1, lastEvent.Properties["A"].LiteralValue());
Assert.False(Thread.CurrentThread.IsThreadPoolThread);
Assert.True(Thread.CurrentThread.IsBackground);
Assert.NotEqual(pre, post);
}
},
new ForceNewThreadSyncContext());
}
public void FilterExpressionsLogicalOperations()
{
AssertFiltering("A and B",
Some.InformationEvent("{A} {B}", true, true),
Some.InformationEvent("{A} {B}", true, false),
Some.InformationEvent());
}
public void FilterExpressionsEvaluateExistentials()
{
AssertFiltering("AppId is not null",
Some.InformationEvent("{AppId}", 10),
Some.InformationEvent("{AppId}", null),
Some.InformationEvent());
}
public void FilterExpressionsEvaluateStringEquality()
{
AssertFiltering("Fruit = 'Apple'",
Some.InformationEvent("Snacking on {Fruit}", "Apple"),
Some.InformationEvent(),
Some.InformationEvent("Snacking on {Fruit}", "Acerola"));
}
public void SpecifyingMinimumLevelOverridesInWriteToLoggerWritesWarningToSelfLog()
{
var outputs = new List <string>();
using (TemporarySelfLog.SaveTo(outputs))
{
var subSink = new CollectingSink();
var subLogger = new LoggerConfiguration()
.MinimumLevel.Verbose()
.MinimumLevel.Override("Foo.Bar", Debug)
.WriteTo.Sink(subSink)
.CreateLogger();
var logger = new LoggerConfiguration()
.MinimumLevel.Verbose()
.MinimumLevel.Override("Foo.Bar", Warning)
.WriteTo.Logger(subLogger)
.CreateLogger();
var contextLogger = logger.ForContext(Constants.SourceContextPropertyName, "Foo.Bar");
contextLogger.Write(Some.InformationEvent());
}
Assert.EndsWith("Minimum level overrides are not supported on sub-loggers " +
"and may be removed completely in a future version.",
outputs.FirstOrDefault() ?? "");
}
public void UserDefinedFunctionsAreCallableInExpressions()
{
var expr = SerilogExpression.Compile(
"magic(10) + 3 = 55",
new StaticMemberNameResolver(typeof(NameResolverTests)));
Assert.True(Coerce.IsTrue(expr(Some.InformationEvent())));
}
public void ExceptionsThrownByAuditSinksArePropagated()
{
var logger = new LoggerConfiguration()
.AuditTo.Sink(new DelegatingSink(e => { throw new Exception("Boom!"); }))
.CreateLogger();
Assert.Throws <AggregateException>(() => logger.Write(Some.InformationEvent()));
}
public void WithNoSwitchToControlEventsAreStillFiltered()
{
var cls = new ControlledLevelSwitch(null);
cls.Update(LogEventLevel.Warning);
Assert.True(cls.IsIncluded(Some.ErrorEvent()));
Assert.False(cls.IsIncluded(Some.InformationEvent()));
}
public void StructuresAreExposedAsDictionaries()
{
var evt = Some.InformationEvent("{@Person}", new { Name = "nblumhardt" });
var expr = FilterLanguage.CreateFilter("Person");
var val = expr(evt);
var dict = Assert.IsType <Dictionary <string, object> >(val);
Assert.Equal("nblumhardt", dict["Name"]);
}
public void ExceptionsThrownByFiltersArePropagatedIfAuditingEnabled()
{
var logger = new LoggerConfiguration()
.AuditTo.Sink(new DelegatingSink(e => { }))
.Filter.ByExcluding(e => { throw new Exception("Boom!"); })
.CreateLogger();
Assert.Throws <Exception>(() => logger.Write(Some.InformationEvent()));
}
public void ExceptionsThrownByFiltersAreNotPropagated()
{
var logger = new LoggerConfiguration()
.Filter.ByExcluding(e => throw new Exception("Boom!"))
.CreateLogger();
logger.Write(Some.InformationEvent());
Assert.True(true, "No exception reached the caller");
}
public void ExceptionsThrownBySinksAreNotPropagated()
{
var logger = new LoggerConfiguration()
.WriteTo.Sink(new DelegatingSink(e => throw new Exception("Boom!")))
.CreateLogger();
logger.Write(Some.InformationEvent());
Assert.True(true, "No exception reached the caller");
}
public void AuditSinkPropagatesExceptions()
{
var expected = new Exception("Test");
var api = new TestIngestionApi(_ => throw expected);
var sink = new SeqAuditSink(api);
var thrown = Assert.Throws <AggregateException>(() => sink.Emit(Some.InformationEvent()));
Assert.Equal(expected, thrown.GetBaseException());
}
public void WillLogToSeparateFiles()
{
var sink1 = AlternateRollingFileSinkFileSink();
var sink2 = AlternateRollingFileSinkFileSink();
var @event = Some.InformationEvent();
sink1.Emit(@event);
sink2.Emit(@event);
}
public void WhenStreamWrapperSpecifiedIsUsedForRolledFiles()
{
var gzipWrapper = new GZipHooks();
var fileName = Some.String() + ".txt";
using (var temp = new TempFolder())
{
string[] files;
var logEvents = new[]
{
Some.InformationEvent(),
Some.InformationEvent(),
Some.InformationEvent()
};
using (var log = new LoggerConfiguration()
.WriteTo.File(Path.Combine(temp.Path, fileName), rollOnFileSizeLimit: true, fileSizeLimitBytes: 1, hooks: gzipWrapper)
.CreateLogger())
{
foreach (var logEvent in logEvents)
{
log.Write(logEvent);
}
files = Directory.GetFiles(temp.Path)
.OrderBy(p => p, StringComparer.OrdinalIgnoreCase)
.ToArray();
Assert.Equal(3, files.Length);
Assert.True(files[0].EndsWith(fileName), files[0]);
Assert.True(files[1].EndsWith("_001.txt"), files[1]);
Assert.True(files[2].EndsWith("_002.txt"), files[2]);
}
// Ensure the data was written through the wrapping GZipStream, by decompressing and comparing against
// what we wrote
for (var i = 0; i < files.Length; i++)
{
using (var textStream = new MemoryStream())
{
using (var fs = System.IO.File.OpenRead(files[i]))
using (var decompressStream = new GZipStream(fs, CompressionMode.Decompress))
{
decompressStream.CopyTo(textStream);
}
textStream.Position = 0;
var lines = textStream.ReadAllLines();
Assert.Equal(1, lines.Count);
Assert.True(lines[0].EndsWith(logEvents[i].MessageTemplate.Text));
}
}
}
}
public void WhenAnEventIsEnqueuedItIsWrittenToABatch_OnTimer()
{
var pbs = new InMemoryPeriodicBatchingSink(2, TinyWait, TimeSpan.Zero);
var evt = Some.InformationEvent();
pbs.Emit(evt);
Thread.Sleep(TinyWait + TinyWait);
pbs.Stop();
Assert.Equal(1, pbs.Batches.Count);
Assert.False(pbs.WasCalledAfterDisposal);
}
public void WhenAnEventIsEnqueuedItIsWrittenToABatch_FlushWhileRunning()
{
var pbs = new InMemoryPeriodicBatchingSink(2, MicroWait, TinyWait + TinyWait);
var evt = Some.InformationEvent();
pbs.Emit(evt);
Thread.Sleep(TinyWait);
pbs.Dispose();
Assert.Equal(1, pbs.Batches.Count);
Assert.False(pbs.WasCalledAfterDisposal);
}
public void AnIntegerPropertySerializesAsIntegerValue()
{
var name = Some.String();
var value = Some.Int();
var @event = Some.InformationEvent();
@event.AddOrUpdateProperty(new LogEventProperty(name, new ScalarValue(value)));
var formatted = FormatJson(@event);
Assert.AreEqual(value, (int)formatted.Properties[name]);
}
public async Task MinimumLevelIsControlled()
{
const LogEventLevel originalLevel = LogEventLevel.Debug, newLevel = LogEventLevel.Error;
var levelSwitch = new LoggingLevelSwitch(originalLevel);
var api = new TestIngestionApi(_ => Task.FromResult(new IngestionResult(true, HttpStatusCode.Accepted, newLevel)));
var sink = new BatchedSeqSink(api, null, new ControlledLevelSwitch(levelSwitch));
await sink.EmitBatchAsync(new[] { Some.InformationEvent() });
Assert.Equal(newLevel, levelSwitch.MinimumLevel);
}
public void PaddingIsApplied(int n, string format, string expected)
{
var formatter = new MessageTemplateTextFormatter("{ThreadId" + format + "}", null);
var evt = Some.InformationEvent();
evt.AddOrUpdateProperty(new LogEventProperty("ThreadId", new ScalarValue(n)));
var sw = new StringWriter();
formatter.Format(evt, sw);
Assert.Equal(expected, sw.ToString());
}
public void ItCreatesNewFileWhenSizeLimitReached()
{
using (var dir = new TestDirectory())
using (var sizeRollingSink = new AlternateRollingFileSink(dir.LogDirectory, new RawFormatter(), 10))
{
var logEvent = Some.InformationEvent();
sizeRollingSink.Emit(logEvent);
Assert.That(sizeRollingSink.CurrentLogFile.LogFileInfo.Sequence, Is.EqualTo(1));
sizeRollingSink.Emit(logEvent);
Assert.That(sizeRollingSink.CurrentLogFile.LogFileInfo.Sequence, Is.EqualTo(2));
}
}
