From 55cb11fd996d7adb18eb5e4621af76970fe2fcfc Mon Sep 17 00:00:00 2001 From: Dmitry Naumov Date: Thu, 5 May 2016 11:16:05 +0300 Subject: [PATCH 1/4] Prevent LogContext.Enrichers serialization when doing cross-domain calls --- src/Serilog/Context/LogContext.cs | 47 ++++++++++++------- test/Serilog.Tests/Context/LogContextTests.cs | 17 ++++--- 2 files changed, 39 insertions(+), 25 deletions(-) diff --git a/src/Serilog/Context/LogContext.cs b/src/Serilog/Context/LogContext.cs index aad1ba7fa..aee209cca 100644 --- a/src/Serilog/Context/LogContext.cs +++ b/src/Serilog/Context/LogContext.cs @@ -14,6 +14,7 @@ using System; +using System.Runtime.Serialization; using Serilog.Core; using Serilog.Core.Enrichers; using Serilog.Events; @@ -192,18 +193,42 @@ static ImmutableStack Enrichers // ReSharper disable once UnusedAutoPropertyAccessor.Global public static bool PermitCrossAppDomainCalls { get; set; } - sealed class Wrapper : MarshalByRefObject + [Serializable] + sealed class Wrapper : ISerializable { + public Wrapper() + { + } + + Wrapper(SerializationInfo info, StreamingContext context) + { + } + public ImmutableStack Value { get; set; } + + public void GetObjectData(SerializationInfo info, StreamingContext context) + { + // NOTE: actually instead of PermitCrossAppDomainCalls, we can analyze context.State for Remoting/CrossAppDomain flags + if (!PermitCrossAppDomainCalls) + { + info.SetType(typeof(object)); + } + } } - static object GetContext(ImmutableStack value) + static object Wrap(ImmutableStack value) { - var context = !PermitCrossAppDomainCalls ? (object)value : new Wrapper + return new Wrapper { Value = value }; - return context; + } + + static ImmutableStack Unwrap(object data) + { + var wrapper = data as Wrapper; + + return wrapper?.Value; } static ImmutableStack Enrichers @@ -211,23 +236,13 @@ static ImmutableStack Enrichers get { var data = CallContext.LogicalGetData(DataSlotName); - - ImmutableStack context; - if (PermitCrossAppDomainCalls) - { - context = ((Wrapper)data)?.Value; - } - else - { - context = (ImmutableStack)data; - } + var context = Unwrap(data); return context; } set { - var context = GetContext(value); - CallContext.LogicalSetData(DataSlotName, context); + CallContext.LogicalSetData(DataSlotName, Wrap(value)); } } diff --git a/test/Serilog.Tests/Context/LogContextTests.cs b/test/Serilog.Tests/Context/LogContextTests.cs index efcf71422..ceab44122 100644 --- a/test/Serilog.Tests/Context/LogContextTests.cs +++ b/test/Serilog.Tests/Context/LogContextTests.cs @@ -1,11 +1,11 @@ -using System; -using System.IO; -using Xunit; +using Xunit; using Serilog.Context; using Serilog.Events; using Serilog.Core.Enrichers; using Serilog.Tests.Support; #if REMOTING +using System; +using System.IO; using System.Runtime.Remoting.Messaging; #endif using System.Threading; @@ -150,7 +150,7 @@ public async Task ContextPropertiesPersistWhenCrossAppDomainCallsAreEnabled() // since user property types may not be serializable. // Fails if the Serilog assemblies cannot be loaded in the // remote domain. See also LogContext.Suspend() - [Fact(Skip = "Fails when run from Build.ps1, needs more work.")] + [Fact] public void DoesNotPreventCrossDomainCalls() { var projectRoot = Environment.CurrentDirectory; @@ -172,7 +172,7 @@ public void DoesNotPreventCrossDomainCalls() var domaininfo = new AppDomainSetup { ApplicationBase = Path.Combine(projectRoot, @"artifacts\"), - PrivateBinPath = @"testbin\Debug\dnx451;bin\Serilog\Debug\dnx451;bin\Serilog.Tests\Debug\dnx451;".Replace("Debug", configuration) + PrivateBinPath = @"testbin\Debug\dnx451;bin\Serilog\Debug\dnx452;bin\Serilog\Debug\net45;bin\Serilog.Tests\Debug\dnx452;".Replace("Debug", configuration) }; var evidence = AppDomain.CurrentDomain.Evidence; domain = AppDomain.CreateDomain("LogContextTest", evidence, domaininfo); @@ -219,18 +219,17 @@ public class RemotelyCallable : MarshalByRefObject { public bool IsCallable() { - var sw = new StringWriter(); + LogEvent lastEvent = null; var log = new LoggerConfiguration() - .WriteTo.TextWriter(sw, outputTemplate: "{Anything}{Number}") + .WriteTo.Sink(new DelegatingSink(e => lastEvent = e)) .Enrich.FromLogContext() .CreateLogger(); using (LogContext.PushProperty("Number", 42)) log.Information("Hello"); - var s = sw.ToString(); - return s == "42"; + return 42.Equals(lastEvent.Properties["Number"].LiteralValue()); } } #endif From 1a66d179cab7c2e0a3dcd6cc7ef23a4c080d2f78 Mon Sep 17 00:00:00 2001 From: Dmitry Naumov Date: Thu, 5 May 2016 12:03:47 +0300 Subject: [PATCH 2/4] Attempting to fix AppDomain tests --- Build.ps1 | 4 +++- test/Serilog.Tests/Context/LogContextTests.cs | 2 +- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/Build.ps1 b/Build.ps1 index 2e01b0d5d..0d77261f5 100644 --- a/Build.ps1 +++ b/Build.ps1 @@ -36,6 +36,7 @@ function Restore-Packages function Build-Projects { param($Directory, $pack) + $DirectoryName = $Directory.DirectoryName $artifactsFolder = join-path $root "artifacts" @@ -53,7 +54,8 @@ function Build-Projects function Test-Projects { param([string] $DirectoryName) - & dnx -p ("""" + $DirectoryName + """") test; if($LASTEXITCODE -ne 0) { exit 2 } + + & dnx --configuration Release -p ("""" + $DirectoryName + """") test; if($LASTEXITCODE -ne 0) { exit 2 } } function Remove-PathVariable diff --git a/test/Serilog.Tests/Context/LogContextTests.cs b/test/Serilog.Tests/Context/LogContextTests.cs index ceab44122..7cf6b5b1a 100644 --- a/test/Serilog.Tests/Context/LogContextTests.cs +++ b/test/Serilog.Tests/Context/LogContextTests.cs @@ -172,7 +172,7 @@ public void DoesNotPreventCrossDomainCalls() var domaininfo = new AppDomainSetup { ApplicationBase = Path.Combine(projectRoot, @"artifacts\"), - PrivateBinPath = @"testbin\Debug\dnx451;bin\Serilog\Debug\dnx452;bin\Serilog\Debug\net45;bin\Serilog.Tests\Debug\dnx452;".Replace("Debug", configuration) + PrivateBinPath = @"Serilog.Tests.xproj\testbin\Debug\dnx452;Serilog.xproj\testbin\Debug\net45;bin\Serilog\Debug\dnx452;bin\Serilog\Debug\net45;bin\Serilog.Tests\Debug\dnx452;".Replace("Debug", configuration) }; var evidence = AppDomain.CurrentDomain.Evidence; domain = AppDomain.CreateDomain("LogContextTest", evidence, domaininfo); From a7b5f7455315ac4296ddc28e2e296d5585178bf8 Mon Sep 17 00:00:00 2001 From: Dmitry Naumov Date: Sun, 19 Jun 2016 13:20:50 +0300 Subject: [PATCH 3/4] Use ObjectHandle to wrap value stored in CallContext. Remove LogContext.PermitCrossAppDomainCalls/Suspend. --- src/Serilog/Context/ImmutableStack.cs | 20 ----- src/Serilog/Context/LogContext.cs | 75 +------------------ test/Serilog.Tests/Context/LogContextTests.cs | 57 -------------- 3 files changed, 4 insertions(+), 148 deletions(-) diff --git a/src/Serilog/Context/ImmutableStack.cs b/src/Serilog/Context/ImmutableStack.cs index 1e87d2a2c..7dfe105f2 100644 --- a/src/Serilog/Context/ImmutableStack.cs +++ b/src/Serilog/Context/ImmutableStack.cs @@ -14,34 +14,14 @@ using System; using System.Collections.Generic; -#if REMOTING -using System.Runtime.Serialization; -#endif namespace Serilog.Context { - // Needed because of the shallow-copying behaviour of - // LogicalCallContext. -#if REMOTING - [Serializable] - class ImmutableStack : IEnumerable, ISerializable -#else class ImmutableStack : IEnumerable -#endif { readonly ImmutableStack _under; readonly T _top; -#if REMOTING - public ImmutableStack(SerializationInfo info, StreamingContext context) - { - } - - void ISerializable.GetObjectData(SerializationInfo info, StreamingContext context) - { - } -#endif - ImmutableStack() { } diff --git a/src/Serilog/Context/LogContext.cs b/src/Serilog/Context/LogContext.cs index aee209cca..5ff2d2aec 100644 --- a/src/Serilog/Context/LogContext.cs +++ b/src/Serilog/Context/LogContext.cs @@ -14,7 +14,6 @@ using System; -using System.Runtime.Serialization; using Serilog.Core; using Serilog.Core.Enrichers; using Serilog.Events; @@ -23,6 +22,7 @@ using System.Collections.Generic; using System.Threading; #elif REMOTING +using System.Runtime.Remoting; using System.Runtime.Remoting.Messaging; #endif @@ -111,25 +111,6 @@ public static IDisposable PushProperties(params ILogEventEnricher[] properties) return bookmark; } - /// - /// Remove all data from the context so that - /// cross- calls can be made without requiring - /// Serilog assemblies to be present in the remote domain. - /// - /// A token that will restore the suspended log context data, if any. - /// The should not be manipulated further - /// until the return value from this method has been disposed. - /// - public static IDisposable Suspend() - { - var stack = GetOrCreateEnricherStack(); - var bookmark = new ContextStackBookmark(stack); - - Enrichers = null; - - return bookmark; - } - static ImmutableStack GetOrCreateEnricherStack() { var enrichers = Enrichers; @@ -184,65 +165,17 @@ static ImmutableStack Enrichers #elif REMOTING - /// - /// When calling into appdomains without Serilog loaded, e.g. via remoting or during unit testing, - /// it may be necesary to set this value to true so that serialization exceptions are avoided. When possible, - /// using the method in a using block around the call has a lower overhead and - /// should be preferred. - /// - // ReSharper disable once UnusedAutoPropertyAccessor.Global - public static bool PermitCrossAppDomainCalls { get; set; } - - [Serializable] - sealed class Wrapper : ISerializable - { - public Wrapper() - { - } - - Wrapper(SerializationInfo info, StreamingContext context) - { - } - - public ImmutableStack Value { get; set; } - - public void GetObjectData(SerializationInfo info, StreamingContext context) - { - // NOTE: actually instead of PermitCrossAppDomainCalls, we can analyze context.State for Remoting/CrossAppDomain flags - if (!PermitCrossAppDomainCalls) - { - info.SetType(typeof(object)); - } - } - } - - static object Wrap(ImmutableStack value) - { - return new Wrapper - { - Value = value - }; - } - - static ImmutableStack Unwrap(object data) - { - var wrapper = data as Wrapper; - - return wrapper?.Value; - } - static ImmutableStack Enrichers { get { - var data = CallContext.LogicalGetData(DataSlotName); - var context = Unwrap(data); + var objectHandle = CallContext.LogicalGetData(DataSlotName) as ObjectHandle; - return context; + return objectHandle?.Unwrap() as ImmutableStack; } set { - CallContext.LogicalSetData(DataSlotName, Wrap(value)); + CallContext.LogicalSetData(DataSlotName, new ObjectHandle(value)); } } diff --git a/test/Serilog.Tests/Context/LogContextTests.cs b/test/Serilog.Tests/Context/LogContextTests.cs index 7cf6b5b1a..f25c1f3c9 100644 --- a/test/Serilog.Tests/Context/LogContextTests.cs +++ b/test/Serilog.Tests/Context/LogContextTests.cs @@ -17,9 +17,6 @@ public class LogContextTests { public LogContextTests() { -#if REMOTING - LogContext.PermitCrossAppDomainCalls = false; -#endif #if !ASYNCLOCAL CallContext.LogicalSetData(typeof(LogContext).FullName, null); #endif @@ -114,37 +111,6 @@ public async Task ContextPropertiesCrossAsyncCalls() } } -#if REMOTING - [Fact] - 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.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); - } - } -#endif - #if APPDOMAIN // Must not actually try to pass context across domains, // since user property types may not be serializable. @@ -189,29 +155,6 @@ public void DoesNotPreventCrossDomainCalls() } } #endif - - [Fact] - public void WhenSuspendedAllPropertiesAreRemovedFromTheContext() - { - LogEvent lastEvent = null; - - var log = new LoggerConfiguration() - .Enrich.FromLogContext() - .WriteTo.Sink(new DelegatingSink(e => lastEvent = e)) - .CreateLogger(); - - using (LogContext.PushProperty("A1", 1)) - { - using (LogContext.Suspend()) - { - log.Write(Some.InformationEvent()); - Assert.False(lastEvent.Properties.ContainsKey("A1")); - } - - log.Write(Some.InformationEvent()); - Assert.Equal(1, lastEvent.Properties["A1"].LiteralValue()); - } - } } #if REMOTING From 3b55d2dbcefefc97fe0db37258195190bb4a9d5b Mon Sep 17 00:00:00 2001 From: Dmitry Naumov Date: Sun, 19 Jun 2016 19:32:52 +0300 Subject: [PATCH 4/4] Use per AppDomain slot name, so other domain won't accidentally unwrap object reference. --- src/Serilog/Context/LogContext.cs | 2 +- test/Serilog.Tests/Context/LogContextTests.cs | 8 +++----- 2 files changed, 4 insertions(+), 6 deletions(-) diff --git a/src/Serilog/Context/LogContext.cs b/src/Serilog/Context/LogContext.cs index 60b67096b..ce39d0824 100644 --- a/src/Serilog/Context/LogContext.cs +++ b/src/Serilog/Context/LogContext.cs @@ -54,7 +54,7 @@ public static class LogContext #if ASYNCLOCAL static readonly AsyncLocal> Data = new AsyncLocal>(); #elif REMOTING - static readonly string DataSlotName = typeof(LogContext).FullName; + static readonly string DataSlotName = typeof(LogContext).FullName + "@AppDomain" + AppDomain.CurrentDomain.Id; #else // DOTNET_51 [ThreadStatic] static ImmutableStack Data; diff --git a/test/Serilog.Tests/Context/LogContextTests.cs b/test/Serilog.Tests/Context/LogContextTests.cs index c219c34ee..c8e9bc3f0 100644 --- a/test/Serilog.Tests/Context/LogContextTests.cs +++ b/test/Serilog.Tests/Context/LogContextTests.cs @@ -114,9 +114,7 @@ public async Task ContextPropertiesCrossAsyncCalls() #if APPDOMAIN // Must not actually try to pass context across domains, // since user property types may not be serializable. - // Fails if the Serilog assemblies cannot be loaded in the - // remote domain. See also LogContext.Suspend() - [Fact] + [Fact(Skip = "Needs to be updated for dotnet runner.")] public void DoesNotPreventCrossDomainCalls() { var projectRoot = Environment.CurrentDirectory; @@ -137,8 +135,8 @@ public void DoesNotPreventCrossDomainCalls() var domaininfo = new AppDomainSetup { - ApplicationBase = Path.Combine(projectRoot, @"artifacts\"), - PrivateBinPath = @"Serilog.Tests.xproj\testbin\Debug\dnx452;Serilog.xproj\testbin\Debug\net45;bin\Serilog\Debug\dnx452;bin\Serilog\Debug\net45;bin\Serilog.Tests\Debug\dnx452;".Replace("Debug", configuration) + ApplicationBase = projectRoot, + PrivateBinPath = @"test\Serilog.Tests\bin\Debug\net452\win7-x64".Replace("Debug", configuration) }; var evidence = AppDomain.CurrentDomain.Evidence; domain = AppDomain.CreateDomain("LogContextTest", evidence, domaininfo);