diff --git a/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs b/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs index 942532de6e..767d24d51e 100644 --- a/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs +++ b/src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs @@ -472,7 +472,10 @@ private 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.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())), + ex)); } #if !NET45 finally @@ -495,7 +498,10 @@ private void ReadToken(string encodedJson) } catch (Exception ex) { - throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant(LogMessages.IDX14101, encodedJson.Substring(Dot2, Dot2 - Dot1)), ex)); + throw LogHelper.LogExceptionMessage(new ArgumentException(LogHelper.FormatInvariant( + LogMessages.IDX14101, + LogHelper.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(Dot1 + 1, Dot2 - Dot1 - 1), t => t.ToString())), + ex)); } #if !NET45 finally @@ -545,7 +551,10 @@ private 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.MarkAsUnsafeSecurityArtifact(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..2e48d1116e 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 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 467cd3606e..9d2364aeba 100644 --- a/src/Microsoft.IdentityModel.Logging/LogHelper.cs +++ b/src/Microsoft.IdentityModel.Logging/LogHelper.cs @@ -44,6 +44,17 @@ internal static bool HeaderWritten set { _isHeaderWritten = value; } } +#if !NET45 + /// + /// Gets whether logging is enabled at the specified ."/> + /// + /// The log level + /// if logging is enabled at the specified level; otherwise, . + public static bool IsEnabled(EventLogLevel level) => + Logger.IsEnabled(level) || + IdentityModelEventSource.Logger.IsEnabled(EventLogLevelToEventLevel(level), EventKeywords.All); +#endif + /// /// Logs an exception using the event source logger and returns new exception. /// @@ -345,6 +356,12 @@ public static void LogWarning(string message, params object[] args) return (T)Activator.CreateInstance(typeof(T), argumentName, message); } + private static EventLogLevel EventLevelToEventLogLevel(EventLevel eventLevel) => + (uint)(int)eventLevel <= 5 ? (EventLogLevel)eventLevel : EventLogLevel.Error; + + private static EventLevel EventLogLevelToEventLevel(EventLogLevel eventLevel) => + (uint)(int)eventLevel <= 5 ? (EventLevel)eventLevel : EventLevel.Error; + /// /// Formats the string using InvariantCulture /// @@ -372,7 +389,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.HiddenSecurityArtifactString, 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; } @@ -412,11 +439,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 MarkAsUnsafeSecurityArtifact(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..6aaba0c116 100644 --- a/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs +++ b/src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs @@ -14,44 +14,92 @@ 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 _callback; + private readonly Func _disarmCallback; + + /// + /// The ToString callback delegate that returns an unscrubbed SecurityArtifact. + /// + private readonly 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 + /// 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. + /// public SecurityArtifact(object argument, Func toStringCallback) { Argument = argument; - _callback = toStringCallback; + _disarmCallback = toStringCallback; + _callbackUnsafe = null; + } + + /// + /// 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. + /// + /// 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) + { + 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, 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) + return "null"; + else + return _disarmCallback(Argument); } // public string UnsafeToString() { - return Argument?.ToString() ?? "null"; + if (_callbackUnsafe == null || Argument == null) + return ToString(); + else + return _callbackUnsafe(Argument); } } } diff --git a/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs b/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs index 87a060278d..6042fff1b7 100644 --- a/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs +++ b/src/Microsoft.IdentityModel.Protocols.SignedHttpRequest/SignedHttpRequestHandler.cs @@ -660,7 +660,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.MarkAsUnsafeSecurityArtifact(signedHttpRequest.EncodedToken, t => t.ToString())))); } /// diff --git a/src/Microsoft.IdentityModel.Tokens.Saml/Microsoft.IdentityModel.Tokens.Saml.csproj b/src/Microsoft.IdentityModel.Tokens.Saml/Microsoft.IdentityModel.Tokens.Saml.csproj index 8859880f1d..50abc6f968 100644 --- a/src/Microsoft.IdentityModel.Tokens.Saml/Microsoft.IdentityModel.Tokens.Saml.csproj +++ b/src/Microsoft.IdentityModel.Tokens.Saml/Microsoft.IdentityModel.Tokens.Saml.csproj @@ -27,4 +27,8 @@ + + + + diff --git a/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs b/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs index 065eed3884..93a7b9f7c2 100644 --- a/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs +++ b/src/Microsoft.IdentityModel.Tokens.Saml/Saml/SamlSecurityTokenHandler.cs @@ -1213,7 +1213,12 @@ private ClaimsPrincipal ValidateToken(SamlSecurityToken samlToken, string token, identities.ElementAt(0).BootstrapContext = samlToken.Assertion.CanonicalString; } - LogHelper.LogInformation(TokenLogMessages.IDX10241, token); +#if !NET45 + if (LogHelper.IsEnabled(Abstractions.EventLogLevel.Informational)) +#endif + LogHelper.LogInformation( + TokenLogMessages.IDX10241, + 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 7f9bd5dd3b..8e3725330f 100644 --- a/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs +++ b/src/Microsoft.IdentityModel.Tokens.Saml/Saml2/Saml2SecurityTokenHandler.cs @@ -270,7 +270,12 @@ private ClaimsPrincipal ValidateToken(Saml2SecurityToken samlToken, string token if (validationParameters.SaveSigninToken) identity.BootstrapContext = samlToken.Assertion.CanonicalString; - LogHelper.LogInformation(TokenLogMessages.IDX10241, token); +#if !NET45 + if (LogHelper.IsEnabled(Abstractions.EventLogLevel.Informational)) +#endif + LogHelper.LogInformation( + TokenLogMessages.IDX10241, + 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 20e76450e7..d6c15dc531 100644 --- a/src/Microsoft.IdentityModel.Tokens/Validators.cs +++ b/src/Microsoft.IdentityModel.Tokens/Validators.cs @@ -68,7 +68,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.MarkAsUnsafeSecurityArtifact(securityToken, t => t.ToString()))) { InvalidAudience = Utility.SerializeAsSingleCommaDelimitedString(audiences) }); @@ -477,7 +481,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.MarkAsUnsafeSecurityArtifact(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..e33b7d78d5 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.HiddenSecurityArtifactString, 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.HiddenSecurityArtifactString, 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.HiddenSecurityArtifactString, 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.HiddenSecurityArtifactString, 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..94152d78ca --- /dev/null +++ b/test/Microsoft.IdentityModel.Logging.Tests/LogHelperTests.cs @@ -0,0 +1,456 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +namespace Microsoft.IdentityModel.Logging.Tests +{ + using System; + using Microsoft.IdentityModel.Logging; + using Microsoft.IdentityModel.Tokens; + using Xunit; + + // 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}"; + 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.MarkAsUnsafeSecurityArtifact(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_NoException() + { + object arg = "argument"; + LogHelper.MarkAsSecurityArtifact(arg, + null, + obj => string.Format(UnsafeFormat, obj)); + } + + [Fact] + public void MarkAsSecurityArtifactUnsafeCallbackIsNull_NoException() + { + object arg = "argument"; + LogHelper.MarkAsSecurityArtifact(arg, + obj => string.Format(SafeFormat, obj), + null); + } + + [Fact] + public void MarkAsUnsafeOnlySecurityArtifact_ArgumentIsNull_NoException() + { + LogHelper.MarkAsUnsafeSecurityArtifact( + null, + obj => string.Format(UnsafeFormat, obj)); + } + + [Fact] + public void MarkAsUnsafeOnlySecurityArtifactUnsafeCallbackIsNull_NoException() + { + object arg = "argument"; + LogHelper.MarkAsUnsafeSecurityArtifact(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_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() + { + // 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_ExplicitlyMarkedUnsafePropertyNullCallback_ReturnsDefaultScrub() + { + // Arrange + string format = "PII Data: {0} and Token Data: {1}."; + object[] args = new object[] { LogHelper.MarkAsNonPII("data"), LogHelper.MarkAsUnsafeSecurityArtifact("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() + { + // 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.MarkAsUnsafeSecurityArtifact("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#"; + } +}