Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Log Scrubbing] Clean up log messages in Wilson #2339

Merged
merged 4 commits into from
Oct 2, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 12 additions & 3 deletions src/Microsoft.IdentityModel.JsonWebTokens/JsonWebToken.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())),
ex));
}

try
Expand All @@ -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.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(Dot1 + 1, Dot2 - Dot1 - 1), t => t.ToString())),
ex));
}
}
else
Expand Down Expand Up @@ -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.MarkAsUnsafeSecurityArtifact(encodedJson.Substring(0, Dot1), t => t.ToString())),
ex));
}

// dir does not have any key bytes
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,11 @@ private IdentityModelEventSource()
/// </summary>
public static string HiddenPIIString { get; } = "[PII of type '{0}' is hidden. For more details, see https://aka.ms/IdentityModel/PII.]";

/// <summary>
/// String that is used in place of any arguments to log messages if the 'LogCompleteSecurityArtifact' flag is set to false.
/// </summary>
public static string HiddenSecurityArtifactString { get; } = "[Security Artifact of type '{0}' is hidden. For more details, see https://aka.ms/IdentityModel/SecurityArtifactLogging.]";

/// <summary>
/// Indicates whether or the log message header (contains library version, date/time, and PII debugging information) has been written.
/// </summary>
Expand Down
47 changes: 47 additions & 0 deletions src/Microsoft.IdentityModel.Logging/LogHelper.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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.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;
}

Expand Down Expand Up @@ -424,11 +434,48 @@ public static object MarkAsNonPII(object arg)
/// <param name="arg">A log message argument to be marked as SecurityArtifact.</param>
/// <param name="callback">A callback function to log the security artifact safely.</param>
/// <returns>An argument marked as SecurityArtifact.</returns>
/// <remarks>
/// Since even the payload may sometimes contain security artifacts, na�ve disarm algorithms such as removing signatures
/// will not work. For now the <paramref name="callback"/> will only be leveraged if
/// <see cref="IdentityModelEventSource.LogCompleteSecurityArtifact"/> is set and no unsafe callback is provided. Future changes
/// may introduce a support for best effort disarm logging.
/// </remarks>
public static object MarkAsSecurityArtifact(object arg, Func<object, string> callback)
{
return new SecurityArtifact(arg, callback);
}

/// <summary>
/// Marks a log message argument (<paramref name="arg"/>) as SecurityArtifact.
/// </summary>
/// <param name="arg">A log message argument to be marked as SecurityArtifact.</param>
/// <param name="callback">A callback function to log the security artifact safely.</param>
/// <param name="callbackUnsafe">A callback function to log the security artifact without scrubbing.</param>
/// <returns>An argument marked as SecurityArtifact.</returns>
/// <exception cref="ArgumentNullException">if <paramref name="callback"/> is null.</exception>
/// <exception cref="ArgumentNullException">if <paramref name="callbackUnsafe"/> is null.</exception>
/// <remarks>
/// Since even the payload may sometimes contain security artifacts, na�ve disarm algorithms such as removing signatures
/// will not work. For now the <paramref name="callback"/> is currently unused. Future changes
/// may introduce a support for best effort disarm logging which will leverage <paramref name="callback"/>.
/// </remarks>
public static object MarkAsSecurityArtifact(object arg, Func<object, string> callback, Func<object, string> callbackUnsafe)
{
return new SecurityArtifact(arg, callback, callbackUnsafe);
}

/// <summary>
/// Marks a log message argument (<paramref name="arg"/>) as SecurityArtifact.
/// </summary>
/// <param name="arg">A log message argument to be marked as SecurityArtifact.</param>
/// <param name="callbackUnsafe">A callback function to log the security artifact without scrubbing.</param>
/// <returns>An argument marked as SecurityArtifact.</returns>
/// <exception cref="ArgumentNullException">if <paramref name="callbackUnsafe"/> is null.</exception>
public static object MarkAsUnsafeSecurityArtifact(object arg, Func<object, string> callbackUnsafe)
{
return new SecurityArtifact(arg, SecurityArtifact.UnknownSafeTokenCallback, callbackUnsafe);
}

/// <summary>
/// Creates a <see cref="LogEntry"/> by using the provided event level, exception argument, string argument and arguments list.
/// </summary>
Expand Down
69 changes: 58 additions & 11 deletions src/Microsoft.IdentityModel.Logging/SecurityArtifact.cs
Original file line number Diff line number Diff line change
Expand Up @@ -14,44 +14,91 @@ namespace Microsoft.IdentityModel.Logging
/// </remarks>
internal struct SecurityArtifact : ISafeLogSecurityArtifact
{
private const string _scrubbedArtifact = "#ScrubbedArtifact#";
TimHannMSFT marked this conversation as resolved.
Show resolved Hide resolved
TimHannMSFT marked this conversation as resolved.
Show resolved Hide resolved

/// <summary>
/// Argument wrapped with a <see cref="SecurityArtifact"/> structure is considered as SecurityArtifact in the message logging process.
/// </summary>
private object Argument { get; set; }

/// <summary>
/// The ToString callback delegate that return a disarmed SecurityArtifact.
/// The ToString callback delegate that returns a disarmed SecurityArtifact.
/// </summary>
private Func<object, string> _callback;
private readonly Func<object, string> _disarmCallback;

/// <summary>
/// The ToString callback delegate that returns an unscrubbed SecurityArtifact.
/// </summary>
private readonly Func<object, string> _callbackUnsafe;

/// <summary>
/// Creates an instance of <see cref="SecurityArtifact"/> that wraps the <paramref name="argument"/>.
/// </summary>
/// <param name="argument">An argument that is considered as SecurityArtifact.</param>
/// <param name="toStringCallback">A ToString callback.</param>
/// <exception cref="ArgumentNullException">if <paramref name="argument"/> is null.</exception>
/// <param name="toStringCallback">A callback used to disarm the token.</param>
/// <remarks>
/// 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 <paramref name="toStringCallback"/> will only be leveraged if
/// <see cref="IdentityModelEventSource.LogCompleteSecurityArtifact"/> is set and no unsafe callback is provided. Future changes
/// may introduce a support for best effort disarm logging.
/// </remarks>
public SecurityArtifact(object argument, Func<object, string> toStringCallback)
{
Argument = argument;
_callback = toStringCallback;
_disarmCallback = toStringCallback;
TimHannMSFT marked this conversation as resolved.
Show resolved Hide resolved
}

/// <summary>
/// Creates an instance of <see cref="SecurityArtifact"/> that wraps the <paramref name="argument"/>.
/// </summary>
/// <param name="argument">An argument that is considered as SecurityArtifact.</param>
/// <param name="toStringCallback">A ToString callback.</param>
/// <param name="toStringCallbackUnsafe">A ToString callback which will return the unscrubbed artifact.</param>
/// <remarks>
/// 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 <paramref name="toStringCallback"/> is currently unused. Future changes
/// may introduce a support for best effort disarm logging which will leverage <paramref name="toStringCallback"/>.
/// </remarks>
public SecurityArtifact(object argument, Func<object, string> toStringCallback, Func<object, string> toStringCallbackUnsafe)
{
Argument = argument;
_disarmCallback = toStringCallback;
_callbackUnsafe = toStringCallbackUnsafe;
}

/// <summary>
/// A dummy callback which can be leveraged to return a standard scrubbed token in the case where expected token is unknown.
/// </summary>
/// <param name="_">Ignored token.</param>
/// <returns>The standard scrubbed token string.</returns>
public static string UnknownSafeTokenCallback(object _)
TimHannMSFT marked this conversation as resolved.
Show resolved Hide resolved
TimHannMSFT marked this conversation as resolved.
Show resolved Hide resolved
{
return _scrubbedArtifact;
}

/// <summary>
/// Returns a string that represents the <see cref="Argument"/>.
/// </summary>
/// <returns><c>Null</c> if the <see cref="Argument"/> is <see langword="null"/>, otherwise calls <see cref="System.ValueType.ToString()"/> method of the <see cref="Argument"/>.</returns>
/// <returns><c>Null</c> if the <see cref="Argument"/> is <see langword="null"/>, otherwise calls the provided safe callback on <see cref="Argument"/>.</returns>
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);
}

// <inheritdoc/>
public string UnsafeToString()
{
return Argument?.ToString() ?? "null";
if (_callbackUnsafe == null || Argument == null)
return ToString();
else
return _callbackUnsafe(Argument);
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -675,7 +675,11 @@ internal virtual async Task<SecurityKey> 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()))));
}

/// <summary>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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.MarkAsUnsafeSecurityArtifact(token, t => t.ToString()));

return new ClaimsPrincipal(identities);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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(
TimHannMSFT marked this conversation as resolved.
Show resolved Hide resolved
TokenLogMessages.IDX10241,
LogHelper.MarkAsUnsafeSecurityArtifact(token, t => t.ToString()));

return new ClaimsPrincipal(identity);
}
Expand Down
11 changes: 9 additions & 2 deletions src/Microsoft.IdentityModel.Tokens/Validators.cs
Original file line number Diff line number Diff line change
Expand Up @@ -69,7 +69,11 @@ public static void ValidateAudience(IEnumerable<string> 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)
});
Expand Down Expand Up @@ -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.MarkAsUnsafeSecurityArtifact(securityToken, t => t.ToString()))));
return;
}

Expand Down
Loading