From d6976aa80d4c785e4435a3da8662b83a8924410f Mon Sep 17 00:00:00 2001 From: Levi Broderick Date: Wed, 29 Jul 2020 15:33:18 -0700 Subject: [PATCH] Add BinaryFormatter auditing EventSource (#39874) --- ...em.Runtime.Serialization.Formatters.csproj | 1 + .../Formatters/Binary/BinaryFormatter.Core.cs | 21 +- .../Binary/BinaryFormatterEventSource.cs | 102 +++++++++ .../Formatters/Binary/BinaryObjectInfo.cs | 7 +- .../tests/BinaryFormatterEventSourceTests.cs | 216 ++++++++++++++++++ ...time.Serialization.Formatters.Tests.csproj | 5 +- 6 files changed, 346 insertions(+), 6 deletions(-) create mode 100644 src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatterEventSource.cs create mode 100644 src/libraries/System.Runtime.Serialization.Formatters/tests/BinaryFormatterEventSourceTests.cs diff --git a/src/libraries/System.Runtime.Serialization.Formatters/src/System.Runtime.Serialization.Formatters.csproj b/src/libraries/System.Runtime.Serialization.Formatters/src/System.Runtime.Serialization.Formatters.csproj index dba845f2eeb90..124a497c46379 100644 --- a/src/libraries/System.Runtime.Serialization.Formatters/src/System.Runtime.Serialization.Formatters.csproj +++ b/src/libraries/System.Runtime.Serialization.Formatters/src/System.Runtime.Serialization.Formatters.csproj @@ -61,6 +61,7 @@ + diff --git a/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatter.Core.cs b/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatter.Core.cs index 95f281f633978..939b78ad9535d 100644 --- a/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatter.Core.cs +++ b/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatter.Core.cs @@ -39,6 +39,7 @@ public object Deserialize(Stream serializationStream) }; try { + BinaryFormatterEventSource.Log.DeserializationStart(); var parser = new BinaryParser(serializationStream, reader); return reader.Deserialize(parser); } @@ -50,6 +51,10 @@ public object Deserialize(Stream serializationStream) { throw new SerializationException(SR.Serialization_CorruptedStream, e); } + finally + { + BinaryFormatterEventSource.Log.DeserializationStop(); + } } [Obsolete(Obsoletions.BinaryFormatterMessage, DiagnosticId = Obsoletions.BinaryFormatterDiagId, UrlFormat = Obsoletions.SharedUrlFormat)] @@ -73,10 +78,18 @@ public void Serialize(Stream serializationStream, object graph) _assemblyFormat = _assemblyFormat, }; - var sow = new ObjectWriter(_surrogates, _context, formatterEnums, _binder); - BinaryFormatterWriter binaryWriter = new BinaryFormatterWriter(serializationStream, sow, _typeFormat); - sow.Serialize(graph, binaryWriter); - _crossAppDomainArray = sow._crossAppDomainArray; + try + { + BinaryFormatterEventSource.Log.SerializationStart(); + var sow = new ObjectWriter(_surrogates, _context, formatterEnums, _binder); + BinaryFormatterWriter binaryWriter = new BinaryFormatterWriter(serializationStream, sow, _typeFormat); + sow.Serialize(graph, binaryWriter); + _crossAppDomainArray = sow._crossAppDomainArray; + } + finally + { + BinaryFormatterEventSource.Log.SerializationStop(); + } } } } diff --git a/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatterEventSource.cs b/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatterEventSource.cs new file mode 100644 index 0000000000000..ca8efd4c0978a --- /dev/null +++ b/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryFormatterEventSource.cs @@ -0,0 +1,102 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics; +using System.Diagnostics.Tracing; + +namespace System.Runtime.Serialization.Formatters.Binary +{ + [EventSource( + Name = "System.Runtime.Serialization.Formatters.Binary.BinaryFormatterEventSource")] + internal sealed class BinaryFormatterEventSource : EventSource + { + private const int EventId_SerializationStart = 10; + private const int EventId_SerializationStop = 11; + private const int EventId_SerializingObject = 12; + private const int EventId_DeserializationStart = 20; + private const int EventId_DeserializationStop = 21; + private const int EventId_DeserializingObject = 22; + + public static readonly BinaryFormatterEventSource Log = new BinaryFormatterEventSource(); + + private BinaryFormatterEventSource() + { + } + + [Event(EventId_SerializationStart, Opcode = EventOpcode.Start, Keywords = Keywords.Serialization, Level = EventLevel.Informational, ActivityOptions = EventActivityOptions.Recursive)] + public void SerializationStart() + { + if (IsEnabled(EventLevel.Informational, Keywords.Serialization)) + { + WriteEvent(EventId_SerializationStart); + } + } + + [Event(EventId_SerializationStop, Opcode = EventOpcode.Stop, Keywords = Keywords.Serialization, Level = EventLevel.Informational)] + public void SerializationStop() + { + if (IsEnabled(EventLevel.Informational, Keywords.Serialization)) + { + WriteEvent(EventId_SerializationStop); + } + } + + [NonEvent] + public void SerializingObject(Type type) + { + Debug.Assert(type != null); + + if (IsEnabled(EventLevel.Informational, Keywords.Serialization)) + { + SerializingObject(type.AssemblyQualifiedName); + } + } + + [Event(EventId_SerializingObject, Keywords = Keywords.Serialization, Level = EventLevel.Informational)] + private void SerializingObject(string? typeName) + { + WriteEvent(EventId_SerializingObject, typeName); + } + + [Event(EventId_DeserializationStart, Opcode = EventOpcode.Start, Keywords = Keywords.Deserialization, Level = EventLevel.Informational, ActivityOptions = EventActivityOptions.Recursive)] + public void DeserializationStart() + { + if (IsEnabled(EventLevel.Informational, Keywords.Deserialization)) + { + WriteEvent(EventId_DeserializationStart); + } + } + + [Event(EventId_DeserializationStop, Opcode = EventOpcode.Stop, Keywords = Keywords.Deserialization, Level = EventLevel.Informational)] + public void DeserializationStop() + { + if (IsEnabled(EventLevel.Informational, Keywords.Deserialization)) + { + WriteEvent(EventId_DeserializationStop); + } + } + + [NonEvent] + public void DeserializingObject(Type type) + { + Debug.Assert(type != null); + + if (IsEnabled(EventLevel.Informational, Keywords.Deserialization)) + { + DeserializingObject(type.AssemblyQualifiedName); + } + } + + [Event(EventId_DeserializingObject, Keywords = Keywords.Deserialization, Level = EventLevel.Informational)] + private void DeserializingObject(string? typeName) + { + WriteEvent(EventId_DeserializingObject, typeName); + } + + public class Keywords + { + public const EventKeywords Serialization = (EventKeywords)1; + public const EventKeywords Deserialization = (EventKeywords)2; + } + } +} diff --git a/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryObjectInfo.cs b/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryObjectInfo.cs index c87d6a6fad603..64f4e6ddcd830 100644 --- a/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryObjectInfo.cs +++ b/src/libraries/System.Runtime.Serialization.Formatters/src/System/Runtime/Serialization/Formatters/Binary/BinaryObjectInfo.cs @@ -268,8 +268,11 @@ private void InitMemberInfo() internal string GetAssemblyString() => _binderAssemblyString ?? _cache._assemblyString; - private void InvokeSerializationBinder(SerializationBinder? binder) => + private void InvokeSerializationBinder(SerializationBinder? binder) + { + BinaryFormatterEventSource.Log.SerializingObject(_objectType!); binder?.BindToName(_objectType!, out _binderAssemblyString, out _binderTypeName); + } internal void GetMemberInfo(out string[]? outMemberNames, out Type[]? outMemberTypes, out object?[]? outMemberData) { @@ -392,6 +395,8 @@ internal void Init(Type? objectType, string[] memberNames, Type[]? memberTypes, private void InitReadConstructor(Type objectType, ISurrogateSelector? surrogateSelector, StreamingContext context) { + BinaryFormatterEventSource.Log.DeserializingObject(objectType); + if (objectType.IsArray) { InitNoMembers(); diff --git a/src/libraries/System.Runtime.Serialization.Formatters/tests/BinaryFormatterEventSourceTests.cs b/src/libraries/System.Runtime.Serialization.Formatters/tests/BinaryFormatterEventSourceTests.cs new file mode 100644 index 0000000000000..805b1ad4df481 --- /dev/null +++ b/src/libraries/System.Runtime.Serialization.Formatters/tests/BinaryFormatterEventSourceTests.cs @@ -0,0 +1,216 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; +using System.Diagnostics.Tracing; +using System.IO; +using System.Linq; +using System.Runtime.Serialization.Formatters.Binary; +using System.Threading; +using Xunit; + +namespace System.Runtime.Serialization.Formatters.Tests +{ + [ConditionalClass(typeof(PlatformDetection), nameof(PlatformDetection.IsBinaryFormatterSupported))] + public static class BinaryFormatterEventSourceTests + { + private const string BinaryFormatterEventSourceName = "System.Runtime.Serialization.Formatters.Binary.BinaryFormatterEventSource"; + + [Fact] + public static void RecordsSerialization() + { + using LoggingEventListener listener = new LoggingEventListener(); + + BinaryFormatter formatter = new BinaryFormatter(); + formatter.Serialize(Stream.Null, CreatePerson()); + string[] capturedLog = listener.CaptureLog(); + + string[] expected = new string[] + { + "SerializationStart [Start, 00000001]: ", + "SerializingObject [Info, 00000001]: " + typeof(Person).AssemblyQualifiedName, + "SerializingObject [Info, 00000001]: " + typeof(Address).AssemblyQualifiedName, + "SerializationStop [Stop, 00000001]: ", + }; + + Assert.Equal(expected, capturedLog); + } + + [Fact] + public static void RecordsDeserialization() + { + MemoryStream ms = new MemoryStream(); + BinaryFormatter formatter = new BinaryFormatter(); + formatter.Serialize(ms, CreatePerson()); + ms.Position = 0; + + using LoggingEventListener listener = new LoggingEventListener(); + formatter.Deserialize(ms); + string[] capturedLog = listener.CaptureLog(); + + string[] expected = new string[] + { + "DeserializationStart [Start, 00000002]: ", + "DeserializingObject [Info, 00000002]: " + typeof(Person).AssemblyQualifiedName, + "DeserializingObject [Info, 00000002]: " + typeof(Address).AssemblyQualifiedName, + "DeserializationStop [Stop, 00000002]: ", + }; + + Assert.Equal(expected, capturedLog); + } + + [Fact] + public static void RecordsNestedSerializationCalls() + { + // First, serialization + + using LoggingEventListener listener = new LoggingEventListener(); + + MemoryStream ms = new MemoryStream(); + BinaryFormatter formatter = new BinaryFormatter(); + formatter.Serialize(ms, new ClassWithNestedDeserialization()); + string[] capturedLog = listener.CaptureLog(); + ms.Position = 0; + + string[] expected = new string[] + { + "SerializationStart [Start, 00000001]: ", + "SerializingObject [Info, 00000001]: " + typeof(ClassWithNestedDeserialization).AssemblyQualifiedName, + "SerializationStart [Start, 00000001]: ", + "SerializingObject [Info, 00000001]: " + typeof(Address).AssemblyQualifiedName, + "SerializationStop [Stop, 00000001]: ", + "SerializationStop [Stop, 00000001]: ", + }; + + Assert.Equal(expected, capturedLog); + listener.ClearLog(); + + // Then, deserialization + + ms.Position = 0; + formatter.Deserialize(ms); + capturedLog = listener.CaptureLog(); + + expected = new string[] + { + "DeserializationStart [Start, 00000002]: ", + "DeserializingObject [Info, 00000002]: " + typeof(ClassWithNestedDeserialization).AssemblyQualifiedName, + "DeserializationStart [Start, 00000002]: ", + "DeserializingObject [Info, 00000002]: " + typeof(Address).AssemblyQualifiedName, + "DeserializationStop [Stop, 00000002]: ", + "DeserializationStop [Stop, 00000002]: ", + }; + + Assert.Equal(expected, capturedLog); + } + + private static Person CreatePerson() + { + return new Person() + { + Name = "Some Chap", + HomeAddress = new Address() + { + Street = "123 Anywhere Ln", + City = "Anywhere ST 00000 United States" + } + }; + } + + private sealed class LoggingEventListener : EventListener + { + private readonly Thread _activeThread = Thread.CurrentThread; + private readonly List _log = new List(); + + private void AddToLog(FormattableString message) + { + _log.Add(FormattableString.Invariant(message)); + } + + // Captures the current log + public string[] CaptureLog() + { + return _log.ToArray(); + } + + public void ClearLog() + { + _log.Clear(); + } + + protected override void OnEventSourceCreated(EventSource eventSource) + { + if (eventSource.Name == BinaryFormatterEventSourceName) + { + EnableEvents(eventSource, EventLevel.Verbose); + } + + base.OnEventSourceCreated(eventSource); + } + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + // The test project is parallelized. We want to filter to only events that fired + // on the current thread, otherwise we could throw off the test results. + + if (Thread.CurrentThread != _activeThread) + { + return; + } + + AddToLog($"{eventData.EventName} [{eventData.Opcode}, {(int)eventData.Keywords & int.MaxValue:X8}]: {ParsePayload(eventData.Payload)}"); + base.OnEventWritten(eventData); + } + + private static string ParsePayload(IReadOnlyCollection collection) + { + if (collection?.Count > 0) + { + return string.Join("; ", collection.Select(o => o?.ToString() ?? "")); + } + else + { + return ""; + } + } + } + + [Serializable] + private class Person + { + public string Name { get; set; } + public Address HomeAddress { get; set; } + } + + [Serializable] + private class Address + { + public string Street { get; set; } + public string City { get; set; } + } + + [Serializable] + public class ClassWithNestedDeserialization : ISerializable + { + public ClassWithNestedDeserialization() + { + } + + protected ClassWithNestedDeserialization(SerializationInfo info, StreamingContext context) + { + byte[] serializedData = (byte[])info.GetValue("SomeField", typeof(byte[])); + MemoryStream ms = new MemoryStream(serializedData); + BinaryFormatter formatter = new BinaryFormatter(); + formatter.Deserialize(ms); // should deserialize an 'Address' instance + } + + public void GetObjectData(SerializationInfo info, StreamingContext context) + { + MemoryStream ms = new MemoryStream(); + BinaryFormatter formatter = new BinaryFormatter(); + formatter.Serialize(ms, new Address()); + info.AddValue("SomeField", ms.ToArray()); + } + } + } +} diff --git a/src/libraries/System.Runtime.Serialization.Formatters/tests/System.Runtime.Serialization.Formatters.Tests.csproj b/src/libraries/System.Runtime.Serialization.Formatters/tests/System.Runtime.Serialization.Formatters.Tests.csproj index 7e37cb04eed79..f862142382897 100644 --- a/src/libraries/System.Runtime.Serialization.Formatters/tests/System.Runtime.Serialization.Formatters.Tests.csproj +++ b/src/libraries/System.Runtime.Serialization.Formatters/tests/System.Runtime.Serialization.Formatters.Tests.csproj @@ -16,7 +16,6 @@ - @@ -33,6 +32,10 @@ + + + +