From bbb4417633fcac80c99d449e6ca3fe23ceb7f398 Mon Sep 17 00:00:00 2001 From: Tim Hannifin Date: Tue, 26 Sep 2023 08:59:14 -0700 Subject: [PATCH 1/4] [Log Scrubbing] Clean up log messages in Wilson --- .../JsonWebToken.cs | 15 +- .../IdentityModelEventSource.cs | 5 + .../LogHelper.cs | 47 ++ .../SecurityArtifact.cs | 78 +++- .../SignedHttpRequestHandler.cs | 6 +- .../Saml/SamlSecurityTokenHandler.cs | 4 +- .../Saml2/Saml2SecurityTokenHandler.cs | 4 +- .../Validators.cs | 11 +- .../JwtTokenUtilitiesTests.cs | 45 +- .../LogHelperTests.cs | 402 ++++++++++++++++++ 10 files changed, 589 insertions(+), 28 deletions(-) create mode 100644 test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs diff --git a/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs b/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs index ff12b1f77c..2372984bc4 100644 --- a/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs +++ b/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs @@ -382,7 +382,10 @@ internal void ReadToken(string encodedJson) } catch (Exception ex) { - throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant(LogMessages.IDX14102, encodedJson.Substring(0, Dot1)), ex)); + throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant( + LogMessages.IDX14102, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())), + ex)); } try @@ -391,7 +394,10 @@ internal void ReadToken(string encodedJson) } catch (Exception ex) { - throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant(LogMessages.IDX14101, encodedJson.Substring(Dot1 + 1, Dot2 - Dot1 - 1)), ex)); + throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant( + LogMessages.IDX14101, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(encodedJson.Substring(Dot1 + 1, Dot2 - Dot1 - 1), t => t.ToString())), + ex)); } } else @@ -446,7 +452,10 @@ internal void ReadToken(string encodedJson) } catch (Exception ex) { - throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant(LogMessages.IDX14102, encodedJson.Substring(0, Dot1)), ex)); + throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant( + LogMessages.IDX14102, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())), + ex)); } // dir does not have any key bytes diff --git a/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs b/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs index 290227c45f..25359bdd60 100644 --- a/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs +++ b/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs @@ -45,6 +45,11 @@ private IdentityModelEventSource() /// public static string HiddenPIIString { get; } = "[PII of type '{0}' is hidden. For more details, see https://aka.ms/IdentityModel/PII.]"; + /// + /// String that is used in place of any arguments to log messages if the 'LogCompleteSecurityArtifact' flag is set to false. + /// + public static string HiddenArtifactString { get; } = "[Security Artifact of type '{0}' is hidden. For more details, see https://aka.ms/IdentityModel/SecurityArtifactLogging.]"; + /// /// Indicates whether or the log message header (contains library version, date/time, and PII debugging information) has been written. /// diff --git a/src/Microsoft.IdentityModel.Logging/LogHelper.cs b/src/Microsoft.IdentityModel.Logging/LogHelper.cs index 775841ed65..8d89a372d7 100644 --- a/src/Microsoft.IdentityModel.Logging/LogHelper.cs +++ b/src/Microsoft.IdentityModel.Logging/LogHelper.cs @@ -384,7 +384,17 @@ private static object SanitizeSecurityArtifact(object arg) if (IdentityModelEventSource.LogCompleteSecurityArtifact && arg is ISafeLogSecurityArtifact) return (arg as ISafeLogSecurityArtifact).UnsafeToString(); + else if (arg is ISafeLogSecurityArtifact) + { + // We may later add a further flag which would log a best effort scrubbing of an artifact. E.g. JsonWebToken tries to remove the signature + // in the current implementation. Another flag may be added in the future to allow this middle path but for now, LogCompleteSecurityArtifact + // must be logged to emit any token part (other than specific claim values). + return string.Format(CultureInfo.InvariantCulture, IdentityModelEventSource.HiddenArtifactString, arg?.GetType().ToString() ?? "Null"); + } + // If it's not a ISafeLogSecurityArtifact then just return the object which will be converted to string. + // It's possible a raw string will contain a security artifact and be exposed here but the alternative is to scrub all objects + // which defeats the purpose of the ShowPII flag. return arg; } @@ -424,11 +434,48 @@ public static object MarkAsNonPII(object arg) /// A log message argument to be marked as SecurityArtifact. /// A callback function to log the security artifact safely. /// An argument marked as SecurityArtifact. + /// + /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms such as removing signatures + /// will not work. For now the will only be leveraged if + /// is set and no unsafe callback is provided. Future changes + /// may introduce a support for best effort disarm logging. + /// public static object MarkAsSecurityArtifact(object arg, Func callback) { return new SecurityArtifact(arg, callback); } + /// + /// Marks a log message argument () as SecurityArtifact. + /// + /// A log message argument to be marked as SecurityArtifact. + /// A callback function to log the security artifact safely. + /// A callback function to log the security artifact without scrubbing. + /// An argument marked as SecurityArtifact. + /// if is null. + /// if is null. + /// + /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms such as removing signatures + /// will not work. For now the is currently unused. Future changes + /// may introduce a support for best effort disarm logging which will leverage . + /// + public static object MarkAsSecurityArtifact(object arg, Func callback, Func callbackUnsafe) + { + return new SecurityArtifact(arg, callback, callbackUnsafe); + } + + /// + /// Marks a log message argument () as SecurityArtifact. + /// + /// A log message argument to be marked as SecurityArtifact. + /// A callback function to log the security artifact without scrubbing. + /// An argument marked as SecurityArtifact. + /// if is null. + public static object MarkAsUnsafeOnlySecurityArtifact(object arg, Func callbackUnsafe) + { + return new SecurityArtifact(arg, SecurityArtifact.UnknownSafeTokenCallback, callbackUnsafe); + } + /// /// Creates a by using the provided event level, exception argument, string argument and arguments list. /// diff --git a/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs b/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs index 04db55acd4..8df860c88a 100644 --- a/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs +++ b/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs @@ -14,44 +14,100 @@ namespace Microsoft.IdentityModel.Logging /// internal struct SecurityArtifact : ISafeLogSecurityArtifact { + private const string _scrubbedArtifact = "#ScrubbedArtifact#"; + /// /// Argument wrapped with a structure is considered as SecurityArtifact in the message logging process. /// private object Argument { get; set; } /// - /// The ToString callback delegate that return a disarmed SecurityArtifact. + /// The ToString callback delegate that returns a disarmed SecurityArtifact. + /// + private Func _disarmCallback; + + /// + /// The ToString callback delegate that returns an unscrubbed SecurityArtifact. /// - private Func _callback; + private Func _callbackUnsafe; /// /// Creates an instance of that wraps the . /// /// An argument that is considered as SecurityArtifact. - /// A ToString callback. - /// if is null. + /// A callback used to disarm the token. + /// + /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms such as removing signatures + /// will not work. For now the will only be leveraged if + /// is set and no unsafe callback is provided. Future changes + /// may introduce a support for best effort disarm logging. + /// public SecurityArtifact(object argument, Func toStringCallback) { Argument = argument; - _callback = toStringCallback; + _disarmCallback = toStringCallback; + } + + /// + /// Creates an instance of that wraps the . + /// + /// An argument that is considered as SecurityArtifact. + /// A ToString callback. + /// A ToString callback which will return the unscrubbed artifact. + /// if is null. + /// if is null. + /// + /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms such as removing signatures + /// will not work. For now the is currently unused. Future changes + /// may introduce a support for best effort disarm logging which will leverage . + /// + public SecurityArtifact(object argument, Func toStringCallback, Func toStringCallbackUnsafe) + { + if (toStringCallback == null) + throw new ArgumentNullException(nameof(toStringCallback)); + + if (toStringCallbackUnsafe == null) + throw new ArgumentNullException(nameof (toStringCallbackUnsafe)); + + Argument = argument; + _disarmCallback = toStringCallback; + _callbackUnsafe = toStringCallbackUnsafe; + } + + /// + /// A dummy callback which can be leveraged to return a standard scrubbed token in the case where expected token is unknown. + /// + /// Ignored token. + /// The standard scrubbed token string. + public static string UnknownSafeTokenCallback(object _) + { + return _scrubbedArtifact; } /// /// Returns a string that represents the . /// - /// Null if the is , otherwise calls method of the . + /// Null if the is , otherwise calls the provided safe callback on . public override string ToString() { - if (_callback != null && Argument != null) - return _callback(Argument); - - return Argument?.ToString() ?? "null"; + // Defense in depth, callers should never provide a null callback but publicly exposed method in LogHelper referencing this didn't check. + if (_disarmCallback == null) + return _scrubbedArtifact; + if (Argument == null) + return "null"; + else + return _disarmCallback(Argument); } // public string UnsafeToString() { - return Argument?.ToString() ?? "null"; + if (_callbackUnsafe == null) + return ToString(); + if (Argument == null) + return "null"; + else + return _callbackUnsafe(Argument); } } } diff --git a/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs b/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs index 95cc436a5f..08da7af2c1 100644 --- a/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs +++ b/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs @@ -675,7 +675,11 @@ internal virtual async Task ValidateSignatureAsync(JsonWebToken sig throw LogHelper.LogExceptionMessage(new SignedHttpRequestInvalidSignatureException(LogHelper.FormatInvariant(LogMessages.IDX23009, ex.ToString()), ex)); } - throw LogHelper.LogExceptionMessage(new SignedHttpRequestInvalidSignatureException(LogHelper.FormatInvariant(LogMessages.IDX23034, signedHttpRequest.EncodedToken))); + throw LogHelper.LogExceptionMessage( + new SignedHttpRequestInvalidSignatureException( + LogHelper.FormatInvariant( + LogMessages.IDX23034, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(signedHttpRequest.EncodedToken, t => t.ToString())))); } /// diff --git a/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs b/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs index af0c251173..778ce03cb9 100644 --- a/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs +++ b/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs @@ -1218,7 +1218,9 @@ private ClaimsPrincipal ValidateToken(SamlSecurityToken samlToken, string token, } if (LogHelper.IsEnabled(EventLogLevel.Informational)) - LogHelper.LogInformation(TokenLogMessages.IDX10241, token); + LogHelper.LogInformation( + TokenLogMessages.IDX10241, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(token, t => t.ToString())); return new ClaimsPrincipal(identities); } diff --git a/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs b/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs index 7bbb984e14..8d649cce54 100644 --- a/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs +++ b/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs @@ -269,7 +269,9 @@ private ClaimsPrincipal ValidateToken(Saml2SecurityToken samlToken, string token identity.BootstrapContext = samlToken.Assertion.CanonicalString; if (LogHelper.IsEnabled(EventLogLevel.Informational)) - LogHelper.LogInformation(TokenLogMessages.IDX10241, token); + LogHelper.LogInformation( + TokenLogMessages.IDX10241, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(token, t => t.ToString())); return new ClaimsPrincipal(identity); } diff --git a/src/Microsoft.IdentityModel.Tokens/Validators.cs b/src/Microsoft.IdentityModel.Tokens/Validators.cs index 1119918fcd..1f04d1ca08 100644 --- a/src/Microsoft.IdentityModel.Tokens/Validators.cs +++ b/src/Microsoft.IdentityModel.Tokens/Validators.cs @@ -69,7 +69,11 @@ public static void ValidateAudience(IEnumerable audiences, SecurityToken if (validationParameters.AudienceValidator != null) { if (!validationParameters.AudienceValidator(audiences, securityToken, validationParameters)) - throw LogHelper.LogExceptionMessage(new SecurityTokenInvalidAudienceException(LogHelper.FormatInvariant(LogMessages.IDX10231, securityToken)) + throw LogHelper.LogExceptionMessage( + new SecurityTokenInvalidAudienceException( + LogHelper.FormatInvariant( + LogMessages.IDX10231, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(securityToken, t => t.ToString()))) { InvalidAudience = Utility.SerializeAsSingleCommaDelimitedString(audiences) }); @@ -493,7 +497,10 @@ public static void ValidateTokenReplay(DateTime? expirationTime, string security if (validationParameters.TokenReplayValidator != null) { if (!validationParameters.TokenReplayValidator(expirationTime, securityToken, validationParameters)) - throw LogHelper.LogExceptionMessage(new SecurityTokenReplayDetectedException(LogHelper.FormatInvariant(LogMessages.IDX10228, securityToken))); + throw LogHelper.LogExceptionMessage(new SecurityTokenReplayDetectedException( + LogHelper.FormatInvariant( + LogMessages.IDX10228, + LogHelper.MarkAsUnsafeOnlySecurityArtifact(securityToken, t => t.ToString())))); return; } diff --git a/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs b/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs index 5d146499a6..813217885b 100644 --- a/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs +++ b/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs @@ -59,40 +59,67 @@ public void LogSecurityArtifactTest() LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, LogHelper.MarkAsSecurityArtifact(stringJwe, JwtTokenUtilities.SafeLogJwtToken)))); Assert.DoesNotContain(stringJws, listener.TraceBuffer); - // LogExceptionMessage should log the disarmed jwe since ShowPII is true. + // LogExceptionMessage should log the masked jwe since ShowPII is true but LogCompleteSecurityArtifact is false. IdentityModelEventSource.ShowPII = true; LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, jwe))); - Assert.Contains(jwe.EncodedToken.Substring(0, jwe.EncodedToken.LastIndexOf(".")), listener.TraceBuffer); + Assert.DoesNotContain(jwe.EncodedToken.Substring(0, jwe.EncodedToken.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(jwe.AuthenticationTag, listener.TraceBuffer); + Assert.Contains( + string.Format(IdentityModelEventSource.HiddenArtifactString, jwe.GetType().ToString()), + listener.TraceBuffer); + listener.TraceBuffer = string.Empty; LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, jws))); - Assert.Contains(jws.EncodedToken.Substring(0, jws.EncodedToken.LastIndexOf(".")), listener.TraceBuffer); + Assert.DoesNotContain(jws.EncodedToken.Substring(0, jws.EncodedToken.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(jws.EncodedSignature, listener.TraceBuffer); + Assert.Contains( + string.Format(IdentityModelEventSource.HiddenArtifactString, jws.GetType().ToString()), + listener.TraceBuffer); + listener.TraceBuffer = string.Empty; - LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, LogHelper.MarkAsSecurityArtifact(stringJwe, JwtTokenUtilities.SafeLogJwtToken)))); - Assert.Contains(stringJwe.Substring(0, stringJwe.LastIndexOf(".")), listener.TraceBuffer); + var sa = LogHelper.MarkAsSecurityArtifact(stringJwe, JwtTokenUtilities.SafeLogJwtToken); + LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, sa))); + Assert.DoesNotContain(stringJwe.Substring(0, stringJwe.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(stringJwe.Substring(stringJwe.LastIndexOf(".")), listener.TraceBuffer); + Assert.Contains( + string.Format(IdentityModelEventSource.HiddenArtifactString, sa.GetType().ToString()), + listener.TraceBuffer); + listener.TraceBuffer = string.Empty; - LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, LogHelper.MarkAsSecurityArtifact(stringJws, JwtTokenUtilities.SafeLogJwtToken)))); - Assert.Contains(stringJws.Substring(0, stringJws.LastIndexOf(".")), listener.TraceBuffer); + sa = LogHelper.MarkAsSecurityArtifact(stringJws, JwtTokenUtilities.SafeLogJwtToken); + LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, sa))); + Assert.DoesNotContain(stringJws.Substring(0, stringJws.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(stringJws.Substring(stringJws.LastIndexOf(".")), listener.TraceBuffer); + Assert.Contains( + string.Format(IdentityModelEventSource.HiddenArtifactString, sa.GetType().ToString()), + listener.TraceBuffer); + listener.TraceBuffer = string.Empty; // LogExceptionMessage should log the jwe since CompleteSecurityArtifact is true. IdentityModelEventSource.LogCompleteSecurityArtifact = true; LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, jwe))); Assert.Contains(jwe.EncodedToken, listener.TraceBuffer); + listener.TraceBuffer = string.Empty; LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, jws))); Assert.Contains(jws.EncodedToken, listener.TraceBuffer); listener.TraceBuffer = string.Empty; - LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, LogHelper.MarkAsSecurityArtifact(stringJwe, JwtTokenUtilities.SafeLogJwtToken)))); + LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, LogHelper.MarkAsSecurityArtifact( + stringJwe, + JwtTokenUtilities.SafeLogJwtToken, + t => t.ToString())))); Assert.Contains(stringJwe, listener.TraceBuffer); + listener.TraceBuffer = string.Empty; - LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, LogHelper.MarkAsSecurityArtifact(stringJws, JwtTokenUtilities.SafeLogJwtToken)))); + LogHelper.LogExceptionMessage(new SecurityTokenException(LogHelper.FormatInvariant(TestMessageOneParam, LogHelper.MarkAsSecurityArtifact( + stringJws, + JwtTokenUtilities.SafeLogJwtToken, + t => t.ToString())))); Assert.Contains(stringJws, listener.TraceBuffer); + listener.TraceBuffer = string.Empty; } [Fact] diff --git a/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs new file mode 100644 index 0000000000..e07fc4408f --- /dev/null +++ b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs @@ -0,0 +1,402 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +namespace Microsoft.IdentityModel.Logging.Tests +{ + using System; + using Microsoft.IdentityModel.JsonWebTokens; + using Microsoft.IdentityModel.Logging; + using Microsoft.IdentityModel.Tokens; + using Xunit; + + [Collection("Relying on ShowPII and LogLogCompleteSecurityArtifact")] + public class LogHelperTests + { + private const string SafeFormat = "Safe {0}"; + private const string UnsafeFormat = "Unsafe {0}"; + + [Fact] + public void MarkAsSecurityArtifact_ReturnsSecurityArtifactInstance() + { + object arg = "argument"; + var result = LogHelper.MarkAsSecurityArtifact(arg, + obj => string.Format(SafeFormat, obj), + obj => string.Format(UnsafeFormat, obj)); + + Assert.IsType(result); + } + + [Fact] + public void MarkAsUnsafeOnlySecurityArtifact_ReturnsSecurityArtifactInstance() + { + object arg = "argument"; + var result = LogHelper.MarkAsUnsafeOnlySecurityArtifact(arg, + obj => string.Format(UnsafeFormat, obj)); + + Assert.IsType(result); + } + + [Fact] + public void MarkAsSecurityArtifact_ArgumentIsNull_NoException() + { + // Asserting no exception is thrown for a null argument + LogHelper.MarkAsSecurityArtifact(null, + obj => string.Format(SafeFormat, obj), + obj => string.Format(UnsafeFormat, obj)); + } + + [Fact] + public void MarkAsSecurityArtifactSafeCallbackIsNull_ThrowsArgumentNullException() + { + object arg = "argument"; + Assert.Throws(() => LogHelper.MarkAsSecurityArtifact(arg, + null, + obj => string.Format(UnsafeFormat, obj))); + } + + [Fact] + public void MarkAsSecurityArtifactUnsafeCallbackIsNull_ThrowsArgumentNullException() + { + object arg = "argument"; + Assert.Throws(() => LogHelper.MarkAsSecurityArtifact(arg, + obj => string.Format(SafeFormat, obj), + null)); + } + + [Fact] + public void MarkAsUnsafeOnlySecurityArtifact_ArgumentIsNull_NoException() + { + LogHelper.MarkAsUnsafeOnlySecurityArtifact( + null, + obj => string.Format(UnsafeFormat, obj)); + } + + [Fact] + public void MarkAsUnsafeOnlySecurityArtifactUnsafeCallbackIsNull_ThrowsArgumentNullException() + { + object arg = "argument"; + Assert.Throws(() => LogHelper.MarkAsUnsafeOnlySecurityArtifact(arg, null)); + } + + [Fact] + public void FormatInvariant_NullFormat_ReturnsEmptyString() + { + // Arrange + string format = null; + object[] args = new object[] { "arg1", "arg2" }; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal(string.Empty, result); + } + + [Fact] + public void FormatInvariant_NullArgs_ReturnsFormatString() + { + // Arrange + string format = "This is a {0} string."; + object[] args = null; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal(format, result); + } + + [Fact] + public void FormatInvariant_ShowPIIEnabled_ReturnsPIIData() + { + // Arrange + string format = "This is a {0} string."; + object[] args = new object[] { "sensitive data" }; + IdentityModelEventSource.ShowPII = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal("This is a sensitive data string.", result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + } + + [Fact] + public void FormatInvariant_ShowPIIDisabled_ReturnsSanitizedData() + { + // Arrange + string format = "This is a {0} string."; + object[] args = new object[] { "sensitive data" }; + IdentityModelEventSource.ShowPII = false; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal( + string.Format(format, string.Format(IdentityModelEventSource.HiddenPIIString, args[0].GetType().ToString())), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + } + + [Fact] + public void FormatInvariant_ShowPIIDisabled_ArtifactDisabled_ReturnsSanitizedData() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { "sensitive data", new MockSecurityToken() }; + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + // NOTE: Here that we scrub the token showing PII hidden not SecurityArtifact hidden for the token. + Assert.Equal( + string.Format( + format, + string.Format(IdentityModelEventSource.HiddenPIIString, args[0].GetType().ToString()), + string.Format(IdentityModelEventSource.HiddenPIIString, args[1].GetType().ToString())), + result); + } + + [Fact] + public void FormatInvariant_ShowPIIEnabled_ArtifactEnabled_ReturnsUnscrubbedData() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { "sensitive data", new MockSecurityToken() }; + IdentityModelEventSource.ShowPII = true; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal( + string.Format( + format, + args[0].ToString(), + ((ISafeLogSecurityArtifact)args[1]).UnsafeToString()), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + + [Fact] + public void FormatInvariant_ArtifactEnabled_ShowPIIDisabled_ExplicitlyMarkedProperty_ReturnsSanitizedData() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsSecurityArtifact("token", t => "safe token") }; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + // NOTE: here the security artifact is scrubbed for PII even though the LogCompleteSecurityArtifact is true. + // artifacts often can and do have PII in them so if PII is off, never log non-specific token data. + Assert.Equal( + string.Format( + format, + "data", + string.Format(IdentityModelEventSource.HiddenPIIString, args[1].GetType().ToString())), + result); + + // Reset for other tests + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + + [Fact] + public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedProperty_ReturnsDisarmedToken() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsSecurityArtifact("token", t => "safe token") }; + IdentityModelEventSource.ShowPII = true; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + // NOTE: here the security artifact logs the disarmed token EVEN THOUGH LogCompleteSecurityArtifact is true. This is because no + // callback was provided to return an unsafe string so we default to the safe string. + Assert.Equal( + string.Format( + format, + "data", + "safe token"), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + + [Fact] + public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedPropertyNullCallback_ReturnsDefaultScrub() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsSecurityArtifact("token", null) }; + IdentityModelEventSource.ShowPII = true; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + // NOTE: here the security artifact logs the disarmed token EVEN THOUGH LogCompleteSecurityArtifact is true. This is because no + // callback was provided to return an unsafe string so we default to the safe string. + Assert.Equal( + string.Format( + format, + "data", + "#ScrubbedArtifact#"), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + + [Fact] + public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedProperty_ReturnsTokenData() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsSecurityArtifact("token", t => "safe token", t => t.ToString()) }; + IdentityModelEventSource.ShowPII = true; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal( + string.Format( + format, + "data", + "token"), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + + [Fact] + public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedUnsafeProperty_ReturnsTokenData() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsUnsafeOnlySecurityArtifact("token", t => t.ToString()) }; + IdentityModelEventSource.ShowPII = true; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal( + string.Format( + format, + "data", + "token"), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + + [Fact] + public void FormatInvariant_MultipleNonPIIArgs_NoPII_ReturnsFormattedString() + { + // Arrange + string format = "This is a {0} and {1} string."; + object[] args = new object[] { LogHelper.MarkAsNonPII("first"), LogHelper.MarkAsNonPII("second") }; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal("This is a first and second string.", result); + } + + [Fact] + public void FormatInvariant_MixedArgs_ShowPII_ReturnsFormattedString() + { + // Arrange + string format = "This is a {0} and {1} string."; + object[] args = new object[] { LogHelper.MarkAsNonPII("first"), "second" }; + IdentityModelEventSource.ShowPII = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal("This is a first and second string.", result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + } + + [Fact] + public void FormatInvariant_MixedArgs_NoPII_ReturnsFormattedString() + { + // Arrange + string format = "This is a {0} and {1} string."; + object[] args = new object[] { LogHelper.MarkAsNonPII("first"), "second" }; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal( + string.Format( + format, + args[0].ToString(), + string.Format(IdentityModelEventSource.HiddenPIIString, args[1].GetType().ToString())), + result); + } + + [Fact] + public void FormatInvariant_NoArgs_ReturnsFormatString() + { + // Arrange + string format = "This is a string with no arguments."; + + // Act + var result = LogHelper.FormatInvariant(format); + + // Assert + Assert.Equal("This is a string with no arguments.", result); + } + } + + public class MockSecurityToken : SecurityToken + { + public override string Id { get; } + public override DateTime ValidFrom { get; } + public override DateTime ValidTo { get; } + + public override string Issuer => throw new NotImplementedException(); + + public override SecurityKey SecurityKey => throw new NotImplementedException(); + + public override SecurityKey SigningKey { get => throw new NotImplementedException(); set => throw new NotImplementedException(); } + + public override string UnsafeToString() => "#SECURITY TOKEN#"; + } +} From 06473b3ad7c0e462cc7aaa1eb174c3ece68ee370 Mon Sep 17 00:00:00 2001 From: Tim Hannifin Date: Fri, 29 Sep 2023 13:52:50 -0700 Subject: [PATCH 2/4] Fix spelling nit and clarify collection use in comment --- .../Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs index e07fc4408f..7f9ea2d1d0 100644 --- a/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs +++ b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs @@ -4,12 +4,14 @@ namespace Microsoft.IdentityModel.Logging.Tests { using System; - using Microsoft.IdentityModel.JsonWebTokens; using Microsoft.IdentityModel.Logging; using Microsoft.IdentityModel.Tokens; using Xunit; - [Collection("Relying on ShowPII and LogLogCompleteSecurityArtifact")] + // Leveraging Xunit collections: https://xunit.net/docs/running-tests-in-parallel#parallelism-in-test-frameworks + // Currently this does nothing but if we face issues with tests colliding trying to access ShowPII and LogCompleteSecurityArtifact + // this collection can be used to prevent race conditions. + [Collection("Relying on ShowPII and LogCompleteSecurityArtifact")] public class LogHelperTests { private const string SafeFormat = "Safe {0}"; From 57181aaa1a785ea39da1499852355c3e622875de Mon Sep 17 00:00:00 2001 From: Tim Hannifin Date: Mon, 2 Oct 2023 14:27:49 -0700 Subject: [PATCH 3/4] address PR feedback on spelling and input validation --- .../IdentityModelEventSource.cs | 2 +- .../LogHelper.cs | 2 +- .../SecurityArtifact.cs | 27 +++----- .../JwtTokenUtilitiesTests.cs | 8 +-- .../LogHelperTests.cs | 68 ++++++++++++++++--- 5 files changed, 75 insertions(+), 32 deletions(-) diff --git a/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs b/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs index 25359bdd60..2e48d1116e 100644 --- a/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs +++ b/src/Microsoft.IdentityModel.Logging/IdentityModelEventSource.cs @@ -48,7 +48,7 @@ private IdentityModelEventSource() /// /// String that is used in place of any arguments to log messages if the 'LogCompleteSecurityArtifact' flag is set to false. /// - public static string HiddenArtifactString { get; } = "[Security Artifact of type '{0}' is hidden. For more details, see https://aka.ms/IdentityModel/SecurityArtifactLogging.]"; + public static string HiddenSecurityArtifactString { get; } = "[Security Artifact of type '{0}' is hidden. For more details, see https://aka.ms/IdentityModel/SecurityArtifactLogging.]"; /// /// Indicates whether or the log message header (contains library version, date/time, and PII debugging information) has been written. diff --git a/src/Microsoft.IdentityModel.Logging/LogHelper.cs b/src/Microsoft.IdentityModel.Logging/LogHelper.cs index 8d89a372d7..02d543d489 100644 --- a/src/Microsoft.IdentityModel.Logging/LogHelper.cs +++ b/src/Microsoft.IdentityModel.Logging/LogHelper.cs @@ -389,7 +389,7 @@ private static object SanitizeSecurityArtifact(object arg) // We may later add a further flag which would log a best effort scrubbing of an artifact. E.g. JsonWebToken tries to remove the signature // in the current implementation. Another flag may be added in the future to allow this middle path but for now, LogCompleteSecurityArtifact // must be logged to emit any token part (other than specific claim values). - return string.Format(CultureInfo.InvariantCulture, IdentityModelEventSource.HiddenArtifactString, arg?.GetType().ToString() ?? "Null"); + return string.Format(CultureInfo.InvariantCulture, IdentityModelEventSource.HiddenSecurityArtifactString, arg?.GetType().ToString() ?? "Null"); } // If it's not a ISafeLogSecurityArtifact then just return the object which will be converted to string. diff --git a/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs b/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs index 8df860c88a..f6aa1b9ad1 100644 --- a/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs +++ b/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs @@ -24,12 +24,12 @@ internal struct SecurityArtifact : ISafeLogSecurityArtifact /// /// The ToString callback delegate that returns a disarmed SecurityArtifact. /// - private Func _disarmCallback; + private readonly Func _disarmCallback; /// /// The ToString callback delegate that returns an unscrubbed SecurityArtifact. /// - private Func _callbackUnsafe; + private readonly Func _callbackUnsafe; /// /// Creates an instance of that wraps the . @@ -37,8 +37,8 @@ internal struct SecurityArtifact : ISafeLogSecurityArtifact /// An argument that is considered as SecurityArtifact. /// A callback used to disarm the token. /// - /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms such as removing signatures - /// will not work. For now the will only be leveraged if + /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms (such as removing signatures + /// in the case of JWTs) will not work. For now the will only be leveraged if /// is set and no unsafe callback is provided. Future changes /// may introduce a support for best effort disarm logging. /// @@ -54,21 +54,13 @@ public SecurityArtifact(object argument, Func toStringCallback) /// An argument that is considered as SecurityArtifact. /// A ToString callback. /// A ToString callback which will return the unscrubbed artifact. - /// if is null. - /// if is null. /// - /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms such as removing signatures - /// will not work. For now the is currently unused. Future changes + /// Since even the payload may sometimes contain security artifacts, naïve disarm algorithms (such as removing signatures + /// in the case of JWTs) will not work. For now the is currently unused. Future changes /// may introduce a support for best effort disarm logging which will leverage . /// public SecurityArtifact(object argument, Func toStringCallback, Func toStringCallbackUnsafe) { - if (toStringCallback == null) - throw new ArgumentNullException(nameof(toStringCallback)); - - if (toStringCallbackUnsafe == null) - throw new ArgumentNullException(nameof (toStringCallbackUnsafe)); - Argument = argument; _disarmCallback = toStringCallback; _callbackUnsafe = toStringCallbackUnsafe; @@ -90,7 +82,8 @@ public static string UnknownSafeTokenCallback(object _) /// Null if the is , otherwise calls the provided safe callback on . public override string ToString() { - // Defense in depth, callers should never provide a null callback but publicly exposed method in LogHelper referencing this didn't check. + // Defense in depth, ideally callers will set a callback which actually provides information but, since not initially required in a publicly facing API we + // don't explicitly check and so it's possible we can instrument without a callback in which case we'll return a generic _scrubbedArtifact string. if (_disarmCallback == null) return _scrubbedArtifact; if (Argument == null) @@ -102,10 +95,8 @@ public override string ToString() // public string UnsafeToString() { - if (_callbackUnsafe == null) + if (_callbackUnsafe == null || Argument == null) return ToString(); - if (Argument == null) - return "null"; else return _callbackUnsafe(Argument); } diff --git a/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs b/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs index 813217885b..e33b7d78d5 100644 --- a/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs +++ b/test/Microsoft.IdentityModel.JsonWebTokens.Tests/JwtTokenUtilitiesTests.cs @@ -66,7 +66,7 @@ public void LogSecurityArtifactTest() Assert.DoesNotContain(jwe.EncodedToken.Substring(0, jwe.EncodedToken.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(jwe.AuthenticationTag, listener.TraceBuffer); Assert.Contains( - string.Format(IdentityModelEventSource.HiddenArtifactString, jwe.GetType().ToString()), + string.Format(IdentityModelEventSource.HiddenSecurityArtifactString, jwe.GetType().ToString()), listener.TraceBuffer); listener.TraceBuffer = string.Empty; @@ -74,7 +74,7 @@ public void LogSecurityArtifactTest() Assert.DoesNotContain(jws.EncodedToken.Substring(0, jws.EncodedToken.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(jws.EncodedSignature, listener.TraceBuffer); Assert.Contains( - string.Format(IdentityModelEventSource.HiddenArtifactString, jws.GetType().ToString()), + string.Format(IdentityModelEventSource.HiddenSecurityArtifactString, jws.GetType().ToString()), listener.TraceBuffer); listener.TraceBuffer = string.Empty; @@ -83,7 +83,7 @@ public void LogSecurityArtifactTest() Assert.DoesNotContain(stringJwe.Substring(0, stringJwe.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(stringJwe.Substring(stringJwe.LastIndexOf(".")), listener.TraceBuffer); Assert.Contains( - string.Format(IdentityModelEventSource.HiddenArtifactString, sa.GetType().ToString()), + string.Format(IdentityModelEventSource.HiddenSecurityArtifactString, sa.GetType().ToString()), listener.TraceBuffer); listener.TraceBuffer = string.Empty; @@ -92,7 +92,7 @@ public void LogSecurityArtifactTest() Assert.DoesNotContain(stringJws.Substring(0, stringJws.LastIndexOf(".")), listener.TraceBuffer); Assert.DoesNotContain(stringJws.Substring(stringJws.LastIndexOf(".")), listener.TraceBuffer); Assert.Contains( - string.Format(IdentityModelEventSource.HiddenArtifactString, sa.GetType().ToString()), + string.Format(IdentityModelEventSource.HiddenSecurityArtifactString, sa.GetType().ToString()), listener.TraceBuffer); listener.TraceBuffer = string.Empty; diff --git a/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs index 7f9ea2d1d0..97da1988c4 100644 --- a/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs +++ b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs @@ -48,21 +48,21 @@ public void MarkAsSecurityArtifact_ArgumentIsNull_NoException() } [Fact] - public void MarkAsSecurityArtifactSafeCallbackIsNull_ThrowsArgumentNullException() + public void MarkAsSecurityArtifactSafeCallbackIsNull_NoException() { object arg = "argument"; - Assert.Throws(() => LogHelper.MarkAsSecurityArtifact(arg, + LogHelper.MarkAsSecurityArtifact(arg, null, - obj => string.Format(UnsafeFormat, obj))); + obj => string.Format(UnsafeFormat, obj)); } [Fact] - public void MarkAsSecurityArtifactUnsafeCallbackIsNull_ThrowsArgumentNullException() + public void MarkAsSecurityArtifactUnsafeCallbackIsNull_NoException() { object arg = "argument"; - Assert.Throws(() => LogHelper.MarkAsSecurityArtifact(arg, + LogHelper.MarkAsSecurityArtifact(arg, obj => string.Format(SafeFormat, obj), - null)); + null); } [Fact] @@ -74,10 +74,10 @@ public void MarkAsUnsafeOnlySecurityArtifact_ArgumentIsNull_NoException() } [Fact] - public void MarkAsUnsafeOnlySecurityArtifactUnsafeCallbackIsNull_ThrowsArgumentNullException() + public void MarkAsUnsafeOnlySecurityArtifactUnsafeCallbackIsNull_NoException() { object arg = "argument"; - Assert.Throws(() => LogHelper.MarkAsUnsafeOnlySecurityArtifact(arg, null)); + LogHelper.MarkAsUnsafeOnlySecurityArtifact(arg, null); } [Fact] @@ -245,6 +245,31 @@ public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedPrope IdentityModelEventSource.LogCompleteSecurityArtifact = false; } + [Fact] + public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedProperty_NullArgument() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsSecurityArtifact(null, t => "safe token") }; + IdentityModelEventSource.ShowPII = true; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + Assert.Equal( + string.Format( + format, + "data", + "null"), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + [Fact] public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedPropertyNullCallback_ReturnsDefaultScrub() { @@ -272,6 +297,33 @@ public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedPrope IdentityModelEventSource.LogCompleteSecurityArtifact = false; } + [Fact] + public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedUnsafePropertyNullCallback_ReturnsDefaultScrub() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsUnsafeOnlySecurityArtifact("token", null) }; + IdentityModelEventSource.ShowPII = true; + IdentityModelEventSource.LogCompleteSecurityArtifact = true; + + // Act + var result = LogHelper.FormatInvariant(format, args); + + // Assert + // NOTE: here it logs a generic scrubbed string EVEN THOUGH LogCompleteSecurityArtifact is true. This is because no + // callback was provided to return an unsafe string so we default to the safe string. + Assert.Equal( + string.Format( + format, + "data", + "#ScrubbedArtifact#"), + result); + + // Reset for other tests + IdentityModelEventSource.ShowPII = false; + IdentityModelEventSource.LogCompleteSecurityArtifact = false; + } + [Fact] public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedProperty_ReturnsTokenData() { From 798d542ea6ed6be1ad35bc760375367b0278a723 Mon Sep 17 00:00:00 2001 From: Tim Hannifin Date: Mon, 2 Oct 2023 14:47:33 -0700 Subject: [PATCH 4/4] addressing naming feedback --- .../JsonWebToken.cs | 6 +++--- src/Microsoft.IdentityModel.Logging/LogHelper.cs | 2 +- .../SignedHttpRequestHandler.cs | 2 +- .../Saml/SamlSecurityTokenHandler.cs | 2 +- .../Saml2/Saml2SecurityTokenHandler.cs | 2 +- src/Microsoft.IdentityModel.Tokens/Validators.cs | 4 ++-- .../LogHelperTests.cs | 10 +++++----- 7 files changed, 14 insertions(+), 14 deletions(-) diff --git a/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs b/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs index 2372984bc4..a5fa996b3e 100644 --- a/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs +++ b/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs @@ -384,7 +384,7 @@ internal void ReadToken(string encodedJson) { throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant( LogMessages.IDX14102, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())), + LogHelper.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())), ex)); } @@ -396,7 +396,7 @@ internal void ReadToken(string encodedJson) { throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant( LogMessages.IDX14101, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(encodedJson.Substring(Dot1 + 1, Dot2 - Dot1 - 1), t => t.ToString())), + LogHelper.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(Dot1 + 1, Dot2 - Dot1 - 1), t => t.ToString())), ex)); } } @@ -454,7 +454,7 @@ internal void ReadToken(string encodedJson) { throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant( LogMessages.IDX14102, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())), + LogHelper.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())), ex)); } diff --git a/src/Microsoft.IdentityModel.Logging/LogHelper.cs b/src/Microsoft.IdentityModel.Logging/LogHelper.cs index 02d543d489..f312b8c22e 100644 --- a/src/Microsoft.IdentityModel.Logging/LogHelper.cs +++ b/src/Microsoft.IdentityModel.Logging/LogHelper.cs @@ -471,7 +471,7 @@ public static object MarkAsSecurityArtifact(object arg, Func cal /// A callback function to log the security artifact without scrubbing. /// An argument marked as SecurityArtifact. /// if is null. - public static object MarkAsUnsafeOnlySecurityArtifact(object arg, Func callbackUnsafe) + public static object MarkAsUnsafeSecurityArtifact(object arg, Func callbackUnsafe) { return new SecurityArtifact(arg, SecurityArtifact.UnknownSafeTokenCallback, callbackUnsafe); } diff --git a/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs b/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs index 08da7af2c1..de08e08808 100644 --- a/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs +++ b/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs @@ -679,7 +679,7 @@ internal virtual async Task ValidateSignatureAsync(JsonWebToken sig new SignedHttpRequestInvalidSignatureException( LogHelper.FormatInvariant( LogMessages.IDX23034, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(signedHttpRequest.EncodedToken, t => t.ToString())))); + LogHelper.MarkAsUnsafeSecurityArtifact(signedHttpRequest.EncodedToken, t => t.ToString())))); } /// diff --git a/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs b/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs index 778ce03cb9..e173fea1e7 100644 --- a/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs +++ b/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs @@ -1220,7 +1220,7 @@ private ClaimsPrincipal ValidateToken(SamlSecurityToken samlToken, string token, if (LogHelper.IsEnabled(EventLogLevel.Informational)) LogHelper.LogInformation( TokenLogMessages.IDX10241, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(token, t => t.ToString())); + LogHelper.MarkAsUnsafeSecurityArtifact(token, t => t.ToString())); return new ClaimsPrincipal(identities); } diff --git a/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs b/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs index 8d649cce54..8ff5d48f47 100644 --- a/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs +++ b/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs @@ -271,7 +271,7 @@ private ClaimsPrincipal ValidateToken(Saml2SecurityToken samlToken, string token if (LogHelper.IsEnabled(EventLogLevel.Informational)) LogHelper.LogInformation( TokenLogMessages.IDX10241, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(token, t => t.ToString())); + LogHelper.MarkAsUnsafeSecurityArtifact(token, t => t.ToString())); return new ClaimsPrincipal(identity); } diff --git a/src/Microsoft.IdentityModel.Tokens/Validators.cs b/src/Microsoft.IdentityModel.Tokens/Validators.cs index 1f04d1ca08..5bb7e07530 100644 --- a/src/Microsoft.IdentityModel.Tokens/Validators.cs +++ b/src/Microsoft.IdentityModel.Tokens/Validators.cs @@ -73,7 +73,7 @@ public static void ValidateAudience(IEnumerable audiences, SecurityToken new SecurityTokenInvalidAudienceException( LogHelper.FormatInvariant( LogMessages.IDX10231, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(securityToken, t => t.ToString()))) + LogHelper.MarkAsUnsafeSecurityArtifact(securityToken, t => t.ToString()))) { InvalidAudience = Utility.SerializeAsSingleCommaDelimitedString(audiences) }); @@ -500,7 +500,7 @@ public static void ValidateTokenReplay(DateTime? expirationTime, string security throw LogHelper.LogExceptionMessage(new SecurityTokenReplayDetectedException( LogHelper.FormatInvariant( LogMessages.IDX10228, - LogHelper.MarkAsUnsafeOnlySecurityArtifact(securityToken, t => t.ToString())))); + LogHelper.MarkAsUnsafeSecurityArtifact(securityToken, t => t.ToString())))); return; } diff --git a/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs index 97da1988c4..94152d78ca 100644 --- a/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs +++ b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs @@ -32,7 +32,7 @@ public void MarkAsSecurityArtifact_ReturnsSecurityArtifactInstance() public void MarkAsUnsafeOnlySecurityArtifact_ReturnsSecurityArtifactInstance() { object arg = "argument"; - var result = LogHelper.MarkAsUnsafeOnlySecurityArtifact(arg, + var result = LogHelper.MarkAsUnsafeSecurityArtifact(arg, obj => string.Format(UnsafeFormat, obj)); Assert.IsType(result); @@ -68,7 +68,7 @@ public void MarkAsSecurityArtifactUnsafeCallbackIsNull_NoException() [Fact] public void MarkAsUnsafeOnlySecurityArtifact_ArgumentIsNull_NoException() { - LogHelper.MarkAsUnsafeOnlySecurityArtifact( + LogHelper.MarkAsUnsafeSecurityArtifact( null, obj => string.Format(UnsafeFormat, obj)); } @@ -77,7 +77,7 @@ public void MarkAsUnsafeOnlySecurityArtifact_ArgumentIsNull_NoException() public void MarkAsUnsafeOnlySecurityArtifactUnsafeCallbackIsNull_NoException() { object arg = "argument"; - LogHelper.MarkAsUnsafeOnlySecurityArtifact(arg, null); + LogHelper.MarkAsUnsafeSecurityArtifact(arg, null); } [Fact] @@ -302,7 +302,7 @@ public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedUnsaf { // Arrange string format = "PII Data: {0} and Token Data: {1}."; - object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsUnsafeOnlySecurityArtifact("token", null) }; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsUnsafeSecurityArtifact("token", null) }; IdentityModelEventSource.ShowPII = true; IdentityModelEventSource.LogCompleteSecurityArtifact = true; @@ -354,7 +354,7 @@ public void FormatInvariant_ArtifactEnabled_ShowPIIEnabled_ExplicitlyMarkedUnsaf { // Arrange string format = "PII Data: {0} and Token Data: {1}."; - object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsUnsafeOnlySecurityArtifact("token", t => t.ToString()) }; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsUnsafeSecurityArtifact("token", t => t.ToString()) }; IdentityModelEventSource.ShowPII = true; IdentityModelEventSource.LogCompleteSecurityArtifact = true;