diff --git a/ZB.MOM.WW.Telemetry/README.md b/ZB.MOM.WW.Telemetry/README.md index 1b17d61..912c8d1 100644 --- a/ZB.MOM.WW.Telemetry/README.md +++ b/ZB.MOM.WW.Telemetry/README.md @@ -55,13 +55,19 @@ Trace↔log correlation is automatic: `TraceContextEnricher` reads `Activity.Cur log event and attaches `trace_id` and `span_id`, so log events produced inside a traced request carry the same span identity as the trace backend. -**Redaction reach.** A registered `ILogRedactor` may **remove** or **replace** any top-level -property, and `RedactionEnricher` honours both (a removed key is dropped from the event). The seam -sees the unwrapped value of scalar properties only — a destructured `{@Object}` property is exposed -as its raw Serilog `StructureValue` wrapper, so a redactor can replace/remove the whole structured -property but **cannot** mask a field nested inside it. To protect a sensitive field of a logged -object, log it as its own scalar property (do not destructure it) or remove the whole property by -key. See the `ILogRedactor` XML doc for the full contract. +**Redaction reach.** A registered `ILogRedactor` may **remove** or **replace** any value, and +`RedactionEnricher` honours both (a removed key is dropped from the event). Scalar properties appear +as their unwrapped CLR value; **destructured** properties are projected into mutable views the +redactor can descend into — a `{@Object}` is an `IDictionary` of its fields, a +logged collection an `IList`, a logged dictionary an `IDictionary` — all +recursively, so a field **nested inside** a destructured object can be masked or removed: + +```csharp +if (properties["command"] is IDictionary command) command["apiKey"] = "***"; +``` + +Structure type tags and dictionary keys are preserved on rebuild, and untouched properties are left +intact (not reallocated). See the `ILogRedactor` XML doc for the full contract. --- diff --git a/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ILogRedactor.cs b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ILogRedactor.cs index 049adf0..698c7bf 100644 --- a/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ILogRedactor.cs +++ b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/ILogRedactor.cs @@ -14,16 +14,16 @@ public interface ILogRedactor /// Both removing a key (the property is dropped from the event) and replacing its value are /// honoured by . /// - /// Reach — scalar top-level properties only. Each entry's value is the unwrapped scalar - /// of a Serilog ScalarValue property (so simple string/number/etc. properties such as - /// {apiKey} can be read and masked directly). Destructured / structured properties are - /// not unwrapped: a {@Object} property arrives as the raw Serilog - /// StructureValue wrapper (and a sequence/dictionary as SequenceValue/ - /// DictionaryValue). A redactor can therefore replace or remove the whole - /// top-level property, but it cannot reach a field nested inside a destructured object to - /// mask it selectively. To protect a sensitive field of a logged object, do not destructure it - /// (log the field as its own scalar property), or remove/replace the entire structured property - /// by key. + /// Reach — top-level and nested. A scalar property (e.g. {apiKey}) appears as its + /// unwrapped CLR value, which you can read and replace directly. A destructured property is + /// projected into a mutable view you can descend into: a {@Object} arrives as an + /// IDictionary<string, object?> of its fields, a logged collection as an + /// IList<object?>, and a logged dictionary as an IDictionary<string, object?> + /// keyed by the string form of each key — all recursively. You can therefore mask or remove a field + /// nested inside a destructured object, for example: + /// if (properties["command"] is IDictionary<string, object?> command) command["apiKey"] = "***"; + /// The structure's type tag and a dictionary's original keys are preserved when the event is + /// rebuilt, and properties you do not touch are left intact. /// /// /// The mutable property dictionary for the current log event. diff --git a/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/RedactionEnricher.cs b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/RedactionEnricher.cs index 1251bf9..04f3098 100644 --- a/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/RedactionEnricher.cs +++ b/ZB.MOM.WW.Telemetry/src/ZB.MOM.WW.Telemetry.Serilog/RedactionEnricher.cs @@ -31,26 +31,28 @@ public sealed class RedactionEnricher : ILogEventEnricher /// /// Hands the log event's properties to the registered and reconciles - /// the result back onto the event: values the redactor changed are rewritten via - /// AddOrUpdateProperty, and keys the redactor removed are deleted via - /// RemovePropertyIfPresent. No-op when no redactor is registered or the event carries no + /// the result back onto the event. No-op when no redactor is registered or the event carries no /// properties. /// - /// The redactor sees the unwrapped value of each property; structured - /// values ( from {@Object}, , - /// ) are passed through as their raw Serilog wrapper. A redactor can - /// therefore replace or remove a whole structured top-level property, but cannot reach a field - /// nested inside one — see for the seam's documented reach. + /// Each property is projected into a mutable view the redactor can edit: a scalar is its + /// unwrapped value, and a structured value ( from {@Object}, + /// , ) becomes a nested + /// / the redactor can descend into — + /// recursively — so a field nested inside a destructured object can be masked or removed. After + /// redaction each property is rebuilt and written back only when it actually changed; the + /// structure's type tag and a dictionary's original keys are preserved on rebuild, and keys the + /// redactor removed are deleted via RemovePropertyIfPresent. Properties the redactor does + /// not touch are left intact and are not reallocated. /// /// /// The log event to redact. - /// Factory used to materialize replacement properties. + /// Unused; structured values are rebuilt directly into Serilog values. public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) { ArgumentNullException.ThrowIfNull(logEvent); ArgumentNullException.ThrowIfNull(propertyFactory); - var redactor = ResolveRedactor(); + var redactor = _redactor.Value; if (redactor is null) { return; @@ -62,12 +64,13 @@ public sealed class RedactionEnricher : ILogEventEnricher return; } - var snapshot = new Dictionary(logEvent.Properties.Count); + // Project every property into a mutable view. Scalars stay as their CLR value (zero extra + // allocation); structured values become nested dictionaries/lists carrying enough metadata + // (node kind, type tag, original dictionary keys) to be rebuilt faithfully. + var snapshot = new Dictionary(logEvent.Properties.Count, StringComparer.Ordinal); foreach (var property in logEvent.Properties) { - snapshot[property.Key] = property.Value is ScalarValue scalar - ? scalar.Value - : property.Value; + snapshot[property.Key] = Project(property.Value); } // Capture the original key set so we can honour deletions: any key the redactor drops from @@ -78,10 +81,12 @@ public sealed class RedactionEnricher : ILogEventEnricher foreach (var entry in snapshot) { - if (HasChanged(logEvent, entry.Key, entry.Value)) + // Rebuild the (possibly redacted) value and write it back only when it differs from what + // the event already holds, so an untouched property is never needlessly reallocated. + var rebuilt = Rebuild(entry.Value); + if (!logEvent.Properties.TryGetValue(entry.Key, out var existing) || !ValueEquals(existing, rebuilt)) { - logEvent.AddOrUpdateProperty( - propertyFactory.CreateProperty(entry.Key, entry.Value)); + logEvent.AddOrUpdateProperty(new LogEventProperty(entry.Key, rebuilt)); } } @@ -96,17 +101,238 @@ public sealed class RedactionEnricher : ILogEventEnricher } } - private ILogRedactor? ResolveRedactor() => _redactor.Value; - - private static bool HasChanged(LogEvent logEvent, string key, object? newValue) + /// + /// Projects an immutable Serilog value into a mutable view the redactor can edit. Scalars unwrap + /// to their CLR value; structures/sequences/dictionaries become nested mutable wrappers that + /// remember their kind (and a structure's type tag / a dictionary's original keys) for rebuild. + /// + private static object? Project(LogEventPropertyValue value) { - if (!logEvent.Properties.TryGetValue(key, out var existing)) + switch (value) { - // Redactor added a brand-new property. - return true; + case ScalarValue scalar: + return scalar.Value; + + case StructureValue structure: + var projectedStructure = new ProjectedStructure(structure.TypeTag, structure.Properties.Count); + foreach (var property in structure.Properties) + { + projectedStructure[property.Name] = Project(property.Value); + } + + return projectedStructure; + + case SequenceValue sequence: + var projectedSequence = new ProjectedSequence(sequence.Elements.Count); + foreach (var element in sequence.Elements) + { + projectedSequence.Add(Project(element)); + } + + return projectedSequence; + + case DictionaryValue dictionary: + var projectedDictionary = new ProjectedDictionary(dictionary.Elements.Count); + foreach (var pair in dictionary.Elements) + { + var key = pair.Key.Value?.ToString() ?? NullKey; + projectedDictionary[key] = Project(pair.Value); + projectedDictionary.OriginalKeys[key] = pair.Key; + } + + return projectedDictionary; + + default: + // Unknown future LogEventPropertyValue subtype — pass the wrapper through untouched. + return value; + } + } + + /// + /// Rebuilds a (possibly redacted) projected value back into an immutable Serilog value. The + /// inverse of ; also accepts plain dictionaries/lists a redactor synthesised + /// and leaf CLR values it substituted. + /// + private static LogEventPropertyValue Rebuild(object? projected) + { + switch (projected) + { + case ProjectedStructure structure: + return new StructureValue(RebuildProperties(structure), structure.TypeTag); + + case ProjectedDictionary dictionary: + var pairs = new List>(dictionary.Count); + foreach (var entry in dictionary) + { + var key = dictionary.OriginalKeys.TryGetValue(entry.Key, out var original) + ? original + : new ScalarValue(entry.Key); + pairs.Add(new KeyValuePair(key, Rebuild(entry.Value))); + } + + return new DictionaryValue(pairs); + + case ProjectedSequence sequence: + return new SequenceValue(RebuildElements(sequence)); + + case IDictionary injected: + // A redactor synthesised a new structure (plain dictionary) — rebuild as a StructureValue. + return new StructureValue(RebuildProperties(injected)); + + case IList injectedList: + return new SequenceValue(RebuildElements(injectedList)); + + case LogEventPropertyValue raw: + // An unknown subtype passed through by Project, or a value the redactor set directly. + return raw; + + default: + return new ScalarValue(projected); + } + } + + private static List RebuildProperties(IDictionary source) + { + var properties = new List(source.Count); + foreach (var entry in source) + { + properties.Add(new LogEventProperty(entry.Key, Rebuild(entry.Value))); } - var existingValue = existing is ScalarValue scalar ? scalar.Value : existing; - return !Equals(existingValue, newValue); + return properties; + } + + private static List RebuildElements(IList source) + { + var elements = new List(source.Count); + foreach (var element in source) + { + elements.Add(Rebuild(element)); + } + + return elements; + } + + /// + /// Structural equality between two Serilog values, used to skip writing back a property the + /// redactor left unchanged. Compares scalars by value and structures/sequences/dictionaries by + /// their contents (recursively); unknown kinds fall back to reference equality. + /// + private static bool ValueEquals(LogEventPropertyValue left, LogEventPropertyValue right) + { + switch (left) + { + case ScalarValue scalar when right is ScalarValue otherScalar: + return Equals(scalar.Value, otherScalar.Value); + + case StructureValue structure when right is StructureValue otherStructure: + if (structure.TypeTag != otherStructure.TypeTag + || structure.Properties.Count != otherStructure.Properties.Count) + { + return false; + } + + foreach (var property in structure.Properties) + { + var match = FindProperty(otherStructure, property.Name); + if (match is null || !ValueEquals(property.Value, match.Value)) + { + return false; + } + } + + return true; + + case SequenceValue sequence when right is SequenceValue otherSequence: + if (sequence.Elements.Count != otherSequence.Elements.Count) + { + return false; + } + + for (var i = 0; i < sequence.Elements.Count; i++) + { + if (!ValueEquals(sequence.Elements[i], otherSequence.Elements[i])) + { + return false; + } + } + + return true; + + case DictionaryValue dictionary when right is DictionaryValue otherDictionary: + if (dictionary.Elements.Count != otherDictionary.Elements.Count) + { + return false; + } + + foreach (var pair in dictionary.Elements) + { + var match = FindDictionaryValue(otherDictionary, pair.Key); + if (match is null || !ValueEquals(pair.Value, match)) + { + return false; + } + } + + return true; + + default: + return ReferenceEquals(left, right); + } + } + + private static LogEventProperty? FindProperty(StructureValue structure, string name) + { + foreach (var property in structure.Properties) + { + if (property.Name == name) + { + return property; + } + } + + return null; + } + + private static LogEventPropertyValue? FindDictionaryValue(DictionaryValue dictionary, ScalarValue key) + { + foreach (var pair in dictionary.Elements) + { + if (Equals(pair.Key.Value, key.Value)) + { + return pair.Value; + } + } + + return null; + } + + private const string NullKey = ""; + + /// A destructured object projected to a mutable dictionary; preserves its type tag. + private sealed class ProjectedStructure : Dictionary + { + public ProjectedStructure(string? typeTag, int capacity) + : base(capacity, StringComparer.Ordinal) => TypeTag = typeTag; + + public string? TypeTag { get; } + } + + /// A logged dictionary projected to a mutable dictionary; preserves the original keys. + private sealed class ProjectedDictionary : Dictionary + { + public ProjectedDictionary(int capacity) + : base(capacity, StringComparer.Ordinal) => + OriginalKeys = new Dictionary(capacity, StringComparer.Ordinal); + + public Dictionary OriginalKeys { get; } + } + + /// A logged collection projected to a mutable list. + private sealed class ProjectedSequence : List + { + public ProjectedSequence(int capacity) : base(capacity) + { + } } } diff --git a/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/RedactionTests.cs b/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/RedactionTests.cs index 03870de..c70729d 100644 --- a/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/RedactionTests.cs +++ b/ZB.MOM.WW.Telemetry/tests/ZB.MOM.WW.Telemetry.Serilog.Tests/RedactionTests.cs @@ -34,26 +34,115 @@ public sealed class RedactionTests public void Redact(IDictionary properties) => properties.Remove(_key); } - private sealed class StructuredFieldRedactor : ILogRedactor + /// Masks a field nested inside a destructured {@command} object. + private sealed class NestedFieldRedactor : ILogRedactor { - // Attempts to mask a nested field of a destructured ({@Object}) property by mutating the - // value the seam exposes. Documents that the seam reaches scalar top-level properties only. public void Redact(IDictionary properties) { - if (properties.TryGetValue("command", out var value) && value is StructureValue) + if (properties.TryGetValue("command", out var value) + && value is IDictionary command + && command.ContainsKey("ApiKey")) { - // The seam exposes the raw StructureValue wrapper, not a mutable dictionary of the - // object's fields, so a project redactor cannot reach inside to mask a nested field. - properties["command"] = Masked; + command["ApiKey"] = Masked; } } } + /// Removes a field nested inside a destructured {@command} object. + private sealed class NestedRemovingRedactor : ILogRedactor + { + public void Redact(IDictionary properties) + { + if (properties.TryGetValue("command", out var value) + && value is IDictionary command) + { + command.Remove("ApiKey"); + } + } + } + + /// Masks an element inside a destructured {@items} sequence. + private sealed class SequenceElementRedactor : ILogRedactor + { + public void Redact(IDictionary properties) + { + if (properties.TryGetValue("items", out var value) && value is IList items) + { + for (var i = 0; i < items.Count; i++) + { + if (items[i] is string s && s.StartsWith("secret", StringComparison.Ordinal)) + { + items[i] = Masked; + } + } + } + } + } + + /// Masks a value inside a destructured {@map} dictionary. + private sealed class DictionaryValueRedactor : ILogRedactor + { + public void Redact(IDictionary properties) + { + if (properties.TryGetValue("map", out var value) + && value is IDictionary map + && map.ContainsKey("token")) + { + map["token"] = Masked; + } + } + } + + /// Masks a field two levels deep inside a destructured object graph. + private sealed class DeepFieldRedactor : ILogRedactor + { + public void Redact(IDictionary properties) + { + if (properties.TryGetValue("payload", out var value) + && value is IDictionary payload + && payload.TryGetValue("Inner", out var innerValue) + && innerValue is IDictionary inner + && inner.ContainsKey("ApiKey")) + { + inner["ApiKey"] = Masked; + } + } + } + + // Named types so a destructured StructureValue's TypeTag is deterministic in assertions. + private sealed record Command(string Name, string ApiKey); + + private sealed record Envelope(Inner Inner); + + private sealed record Inner(string ApiKey, string Note); + private static string? ScalarOrNull(LogEvent logEvent, string propertyName) => logEvent.Properties.TryGetValue(propertyName, out var value) && value is ScalarValue scalar ? scalar.Value?.ToString() : null; + /// + /// Builds a logger wired with , logs one event, and returns it — + /// the shared harness for the redaction tests. + /// + private static LogEvent LogWith(ILogRedactor redactor, string template, params object?[] args) + { + var serviceProvider = new ServiceCollection() + .AddSingleton(redactor) + .BuildServiceProvider(); + + var sink = new InMemorySink(); + var options = new ZbTelemetryOptions { ServiceName = "mxgateway" }; + + var loggerConfig = new LoggerConfiguration(); + ZbSerilogConfig.Apply(loggerConfig, options, serviceProvider); + using Logger logger = loggerConfig.WriteTo.Sink(sink).CreateLogger(); + + logger.Information(template, args); + + return Assert.Single(sink.LogEvents); + } + [Fact] public void Registered_redactor_masks_sensitive_property() { @@ -122,36 +211,108 @@ public sealed class RedactionTests } /// - /// Telemetry-002/003: the redaction seam reaches scalar top-level properties only. A - /// destructured ({@Object}) property is exposed to the redactor as the raw Serilog - /// wrapper, so a project redactor cannot mask a field nested - /// inside the object — it can only replace/remove the whole top-level property. This test - /// pins that documented limitation (see ILogRedactor XML doc and the shared contract). + /// Telemetry-002: a redactor can reach a field nested inside a destructured ({@Object}) + /// property and mask it, leaving sibling fields and the structure's type tag intact. /// [Fact] - public void Redactor_cannot_reach_a_field_inside_a_destructured_object() + public void Redactor_masks_a_field_inside_a_destructured_object() { - var serviceProvider = new ServiceCollection() - .AddSingleton(new StructuredFieldRedactor()) - .BuildServiceProvider(); + var logEvent = LogWith( + new NestedFieldRedactor(), + "dispatching {@command}", + new Command("Write", "mxgw_secret")); - var sink = new InMemorySink(); - var options = new ZbTelemetryOptions { ServiceName = "mxgateway" }; + var structure = Assert.IsType(logEvent.Properties["command"]); + var fields = structure.Properties.ToDictionary(p => p.Name, p => p.Value); + Assert.Equal(Masked, (fields["ApiKey"] as ScalarValue)?.Value?.ToString()); + Assert.Equal("Write", (fields["Name"] as ScalarValue)?.Value?.ToString()); + Assert.Equal(nameof(Command), structure.TypeTag); + } - var loggerConfig = new LoggerConfiguration(); - ZbSerilogConfig.Apply(loggerConfig, options, serviceProvider); - using Logger logger = loggerConfig.WriteTo.Sink(sink).CreateLogger(); + /// + /// Telemetry-002: a redactor can remove a field nested inside a destructured object; the + /// field is dropped from the rebuilt structure while siblings survive. + /// + [Fact] + public void Redactor_removes_a_field_inside_a_destructured_object() + { + var logEvent = LogWith( + new NestedRemovingRedactor(), + "dispatching {@command}", + new Command("Write", "mxgw_secret")); - var command = new { Name = "Write", ApiKey = "mxgw_secret" }; - logger.Information("dispatching {@command}", command); + var structure = Assert.IsType(logEvent.Properties["command"]); + var names = structure.Properties.Select(p => p.Name).ToList(); + Assert.DoesNotContain("ApiKey", names); + Assert.Contains("Name", names); + } - var logEvent = Assert.Single(sink.LogEvents); - Assert.True(logEvent.Properties.TryGetValue("command", out var value)); + /// Telemetry-002: a redactor can mask an element nested inside a destructured sequence. + [Fact] + public void Redactor_masks_an_element_inside_a_destructured_sequence() + { + var logEvent = LogWith( + new SequenceElementRedactor(), + "items {@items}", + (object)new[] { "keep", "secret-token" }); - // The property was destructured into a StructureValue and exposed to the redactor as that - // wrapper. The redactor recognized it and replaced the whole top-level property with the - // mask — confirming the seam can only act at top-level granularity for structured values. - Assert.Equal(Masked, (value as ScalarValue)?.Value?.ToString()); + var sequence = Assert.IsType(logEvent.Properties["items"]); + var elements = sequence.Elements.Select(e => (e as ScalarValue)?.Value?.ToString()).ToList(); + Assert.Equal(new[] { "keep", Masked }, elements); + } + + /// Telemetry-002: a redactor can mask a value nested inside a destructured dictionary. + [Fact] + public void Redactor_masks_a_value_inside_a_destructured_dictionary() + { + var map = new Dictionary { ["user"] = "alice", ["token"] = "secret" }; + + var logEvent = LogWith(new DictionaryValueRedactor(), "map {@map}", map); + + var dictionary = Assert.IsType(logEvent.Properties["map"]); + var pairs = dictionary.Elements.ToDictionary( + e => (string)e.Key.Value!, + e => (e.Value as ScalarValue)?.Value?.ToString()); + Assert.Equal("alice", pairs["user"]); + Assert.Equal(Masked, pairs["token"]); + } + + /// Telemetry-002: nested reach is recursive — a field two levels deep is reachable. + [Fact] + public void Redactor_masks_a_field_two_levels_deep() + { + var logEvent = LogWith( + new DeepFieldRedactor(), + "payload {@payload}", + new Envelope(new Inner("secret", "keep"))); + + var outer = Assert.IsType(logEvent.Properties["payload"]); + var innerValue = outer.Properties.Single(p => p.Name == "Inner").Value; + var inner = Assert.IsType(innerValue); + var fields = inner.Properties.ToDictionary(p => p.Name, p => p.Value); + Assert.Equal(Masked, (fields["ApiKey"] as ScalarValue)?.Value?.ToString()); + Assert.Equal("keep", (fields["Note"] as ScalarValue)?.Value?.ToString()); + } + + /// + /// A structured property the redactor does not touch must survive redaction unchanged + /// (siblings, values, and type tag intact) even while a scalar property is masked. + /// + [Fact] + public void Untouched_structured_property_survives_redaction_intact() + { + var logEvent = LogWith( + new FakeRedactor(), + "dispatching {apiKey} {@command}", + "mxgw_secret", + new Command("Write", "open")); + + Assert.Equal(Masked, ScalarOrNull(logEvent, "apiKey")); + var structure = Assert.IsType(logEvent.Properties["command"]); + var fields = structure.Properties.ToDictionary(p => p.Name, p => p.Value); + Assert.Equal("Write", (fields["Name"] as ScalarValue)?.Value?.ToString()); + Assert.Equal("open", (fields["ApiKey"] as ScalarValue)?.Value?.ToString()); + Assert.Equal(nameof(Command), structure.TypeTag); } [Fact]