diff --git a/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngCbcAuthenticatedEncryptionOptions.cs b/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngCbcAuthenticatedEncryptionOptions.cs index bd187df3..07819cd5 100644 --- a/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngCbcAuthenticatedEncryptionOptions.cs +++ b/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngCbcAuthenticatedEncryptionOptions.cs @@ -111,11 +111,7 @@ private BCryptAlgorithmHandle GetHmacAlgorithmHandle(ILogger logger) throw Error.Common_PropertyCannotBeNullOrEmpty(nameof(HashAlgorithm)); } - if (logger.IsVerboseLevelEnabled()) - { - logger.LogVerboseF($"Opening CNG algorithm '{HashAlgorithm}' from provider '{HashAlgorithmProvider}' with HMAC."); - } - + logger.OpeningCNGAlgorithmFromProviderWithHMAC(HashAlgorithm, HashAlgorithmProvider); BCryptAlgorithmHandle algorithmHandle = null; // Special-case cached providers @@ -152,10 +148,7 @@ private BCryptAlgorithmHandle GetSymmetricBlockCipherAlgorithmHandle(ILogger log throw Error.Common_PropertyMustBeNonNegative(nameof(EncryptionAlgorithmKeySize)); } - if (logger.IsVerboseLevelEnabled()) - { - logger.LogVerboseF($"Opening CNG algorithm '{EncryptionAlgorithm}' from provider '{EncryptionAlgorithmProvider}' with chaining mode CBC."); - } + logger.OpeningCNGAlgorithmFromProviderWithChainingModeCBC(EncryptionAlgorithm, EncryptionAlgorithmProvider); BCryptAlgorithmHandle algorithmHandle = null; diff --git a/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngGcmAuthenticatedEncryptionOptions.cs b/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngGcmAuthenticatedEncryptionOptions.cs index 99ab80cd..1390274b 100644 --- a/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngGcmAuthenticatedEncryptionOptions.cs +++ b/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/CngGcmAuthenticatedEncryptionOptions.cs @@ -92,11 +92,7 @@ private BCryptAlgorithmHandle GetSymmetricBlockCipherAlgorithmHandle(ILogger log BCryptAlgorithmHandle algorithmHandle = null; - if (logger.IsVerboseLevelEnabled()) - { - logger.LogVerboseF($"Opening CNG algorithm '{EncryptionAlgorithm}' from provider '{EncryptionAlgorithmProvider}' with chaining mode GCM."); - } - + logger.OpeningCNGAlgorithmFromProviderWithChainingModeGCM(EncryptionAlgorithm, EncryptionAlgorithmProvider); // Special-case cached providers if (EncryptionAlgorithmProvider == null) { diff --git a/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/ManagedAuthenticatedEncryptionOptions.cs b/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/ManagedAuthenticatedEncryptionOptions.cs index c3bddbe5..6c8dc804 100644 --- a/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/ManagedAuthenticatedEncryptionOptions.cs +++ b/src/Microsoft.AspNet.DataProtection/AuthenticatedEncryption/ManagedAuthenticatedEncryptionOptions.cs @@ -86,11 +86,7 @@ private Func GetKeyedHashAlgorithmFactory(ILogger logger) throw Error.Common_PropertyCannotBeNullOrEmpty(nameof(ValidationAlgorithmType)); } - if (logger.IsVerboseLevelEnabled()) - { - logger.LogVerboseF($"Using managed keyed hash algorithm '{ValidationAlgorithmType.FullName}'."); - } - + logger.UsingManagedKeyedHashAlgorithm(ValidationAlgorithmType.FullName); if (ValidationAlgorithmType == typeof(HMACSHA256)) { return () => new HMACSHA256(); @@ -118,10 +114,7 @@ private Func GetSymmetricBlockCipherAlgorithmFactory(ILogger throw Error.Common_PropertyMustBeNonNegative(nameof(EncryptionAlgorithmKeySize)); } - if (logger.IsVerboseLevelEnabled()) - { - logger.LogVerboseF($"Using managed symmetric algorithm '{EncryptionAlgorithmType.FullName}'."); - } + logger.UsingManagedSymmetricAlgorithm(EncryptionAlgorithmType.FullName); if (EncryptionAlgorithmType == typeof(Aes)) { diff --git a/src/Microsoft.AspNet.DataProtection/EphemeralDataProtectionProvider.cs b/src/Microsoft.AspNet.DataProtection/EphemeralDataProtectionProvider.cs index 7ee3de1a..ac6f1dc7 100644 --- a/src/Microsoft.AspNet.DataProtection/EphemeralDataProtectionProvider.cs +++ b/src/Microsoft.AspNet.DataProtection/EphemeralDataProtectionProvider.cs @@ -48,10 +48,7 @@ public EphemeralDataProtectionProvider(IServiceProvider services) } var logger = services.GetLogger(); - if (logger.IsWarningLevelEnabled()) - { - logger.LogWarning("Using ephemeral data protection provider. Payloads will be undecipherable upon application shutdown."); - } + logger.UsingEphemeralDataProtectionProvider(); _dataProtectionProvider = new KeyRingBasedDataProtectionProvider(keyringProvider, services); } diff --git a/src/Microsoft.AspNet.DataProtection/KeyManagement/DefaultKeyResolver.cs b/src/Microsoft.AspNet.DataProtection/KeyManagement/DefaultKeyResolver.cs index 242221eb..48e9684c 100644 --- a/src/Microsoft.AspNet.DataProtection/KeyManagement/DefaultKeyResolver.cs +++ b/src/Microsoft.AspNet.DataProtection/KeyManagement/DefaultKeyResolver.cs @@ -54,10 +54,7 @@ private bool CanCreateAuthenticatedEncryptor(IKey key) } catch (Exception ex) { - if (_logger.IsWarningLevelEnabled()) - { - _logger.LogWarningF(ex, $"Key {key.KeyId:B} is ineligible to be the default key because its {nameof(IKey.CreateEncryptorInstance)} method failed."); - } + _logger.KeyIsIneligibleToBeTheDefaultKeyBecauseItsMethodFailed(key.KeyId, nameof(IKey.CreateEncryptorInstance), ex); return false; } } @@ -72,18 +69,12 @@ private IKey FindDefaultKey(DateTimeOffset now, IEnumerable allKeys, out I if (preferredDefaultKey != null) { - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Considering key {preferredDefaultKey.KeyId:B} with expiration date {preferredDefaultKey.ExpirationDate:u} as default key."); - } + _logger.ConsideringKeyWithExpirationDateAsDefaultKey(preferredDefaultKey.KeyId, preferredDefaultKey.ExpirationDate); // if the key has been revoked or is expired, it is no longer a candidate if (preferredDefaultKey.IsRevoked || preferredDefaultKey.IsExpired(now) || !CanCreateAuthenticatedEncryptor(preferredDefaultKey)) { - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Key {preferredDefaultKey.KeyId:B} is no longer under consideration as default key because it is expired, revoked, or cannot be deciphered."); - } + _logger.KeyIsNoLongerUnderConsiderationAsDefault(preferredDefaultKey.KeyId); preferredDefaultKey = null; } } @@ -104,9 +95,9 @@ private IKey FindDefaultKey(DateTimeOffset now, IEnumerable allKeys, out I && !key.IsExpired(now + _keyPropagationWindow) && !key.IsRevoked); - if (callerShouldGenerateNewKey && _logger.IsVerboseLevelEnabled()) + if (callerShouldGenerateNewKey) { - _logger.LogVerbose("Default key expiration imminent and repository contains no viable successor. Caller should generate a successor."); + _logger.DefaultKeyExpirationImminentAndRepository(); } fallbackKey = null; @@ -127,10 +118,7 @@ orderby key.CreationDate ascending where !key.IsRevoked && CanCreateAuthenticatedEncryptor(key) select key).FirstOrDefault(); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerbose("Repository contains no viable default key. Caller should generate a key with immediate activation."); - } + _logger.RepositoryContainsNoViableDefaultKey(); callerShouldGenerateNewKey = true; return null; diff --git a/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingBasedDataProtector.cs b/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingBasedDataProtector.cs index 0a29811b..9e2ef2f2 100644 --- a/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingBasedDataProtector.cs +++ b/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingBasedDataProtector.cs @@ -111,7 +111,7 @@ public byte[] Protect(byte[] plaintext) if (_logger.IsDebugLevelEnabled()) { - _logger.LogDebugF($"Performing protect operation to key {defaultKeyId:B} with purposes {JoinPurposesForLog(Purposes)}."); + _logger.PerformingProtectOperationToKeyWithPurposes(defaultKeyId, JoinPurposesForLog(Purposes)); } // We'll need to apply the default key id to the template if it hasn't already been applied. @@ -236,7 +236,7 @@ private byte[] UnprotectCore(byte[] protectedData, bool allowOperationsOnRevoked if (_logger.IsDebugLevelEnabled()) { - _logger.LogDebugF($"Performing unprotect operation to key {keyIdFromPayload:B} with purposes {JoinPurposesForLog(Purposes)}."); + _logger.PerformingUnprotectOperationToKeyWithPurposes(keyIdFromPayload, JoinPurposesForLog(Purposes)); } // Find the correct encryptor in the keyring. @@ -245,10 +245,7 @@ private byte[] UnprotectCore(byte[] protectedData, bool allowOperationsOnRevoked var requestedEncryptor = currentKeyRing.GetAuthenticatedEncryptorByKeyId(keyIdFromPayload, out keyWasRevoked); if (requestedEncryptor == null) { - if (_logger.IsDebugLevelEnabled()) - { - _logger.LogDebugF($"Key {keyIdFromPayload:B} was not found in the key ring. Unprotect operation cannot proceed."); - } + _logger.KeyWasNotFoundInTheKeyRingUnprotectOperationCannotProceed(keyIdFromPayload); throw Error.Common_KeyNotFound(keyIdFromPayload); } @@ -264,18 +261,12 @@ private byte[] UnprotectCore(byte[] protectedData, bool allowOperationsOnRevoked { if (allowOperationsOnRevokedKeys) { - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Key {keyIdFromPayload:B} was revoked. Caller requested unprotect operation proceed regardless."); - } + _logger.KeyWasRevokedCallerRequestedUnprotectOperationProceedRegardless(keyIdFromPayload); status = UnprotectStatus.DecryptionKeyWasRevoked; } else { - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Key {keyIdFromPayload:B} was revoked. Unprotect operation cannot proceed."); - } + _logger.KeyWasRevokedUnprotectOperationCannotProceed(keyIdFromPayload); throw Error.Common_KeyRevoked(keyIdFromPayload); } } diff --git a/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingProvider.cs b/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingProvider.cs index c5cff618..c41e45f3 100644 --- a/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingProvider.cs +++ b/src/Microsoft.AspNet.DataProtection/KeyManagement/KeyRingProvider.cs @@ -45,10 +45,7 @@ private CacheableKeyRing CreateCacheableKeyRingCore(DateTimeOffset now, IKey key return CreateCacheableKeyRingCoreStep2(now, cacheExpirationToken, defaultKeyPolicy.DefaultKey, allKeys); } - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerbose("Policy resolution states that a new key should be added to the key ring."); - } + _logger.PolicyResolutionStatesThatANewKeyShouldBeAddedToTheKeyRing(); // We shouldn't call CreateKey more than once, else we risk stack diving. This code path shouldn't // get hit unless there was an ineligible key with an activation date slightly later than the one we @@ -69,18 +66,12 @@ private CacheableKeyRing CreateCacheableKeyRingCore(DateTimeOffset now, IKey key var keyToUse = defaultKeyPolicy.DefaultKey ?? defaultKeyPolicy.FallbackKey; if (keyToUse == null) { - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogError("The key ring does not contain a valid default key, and the key manager is configured with auto-generation of keys disabled."); - } + _logger.KeyRingDoesNotContainValidDefaultKey(); throw new InvalidOperationException(Resources.KeyRingProvider_NoDefaultKey_AutoGenerateDisabled); } else { - if (_logger.IsWarningLevelEnabled()) - { - _logger.LogWarningF($"Policy resolution states that a new key should be added to the key ring, but automatic generation of keys is disabled. Using fallback key {keyToUse.KeyId:B} with expiration {keyToUse.ExpirationDate:u} as default key."); - } + _logger.UsingFallbackKeyWithExpirationAsDefaultKey(keyToUse.KeyId, keyToUse.ExpirationDate); return CreateCacheableKeyRingCoreStep2(now, cacheExpirationToken, keyToUse, allKeys); } } @@ -109,10 +100,7 @@ private CacheableKeyRing CreateCacheableKeyRingCoreStep2(DateTimeOffset now, Can // Invariant: our caller ensures that CreateEncryptorInstance succeeded at least once Debug.Assert(defaultKey.CreateEncryptorInstance() != null); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Using key {defaultKey.KeyId:B} as the default key."); - } + _logger.UsingKeyAsDefaultKey(defaultKey.KeyId); DateTimeOffset nextAutoRefreshTime = now + GetRefreshPeriodWithJitter(_keyManagementOptions.KeyRingRefreshPeriod); @@ -165,9 +153,9 @@ internal IKeyRing GetCurrentKeyRingCore(DateTime utcNow) return existingCacheableKeyRing.KeyRing; } - if (existingCacheableKeyRing != null && _logger.IsVerboseLevelEnabled()) + if (existingCacheableKeyRing != null) { - _logger.LogVerbose("Existing cached key ring is expired. Refreshing."); + _logger.ExistingCachedKeyRingIsExpired(); } // It's up to us to refresh the cached keyring. @@ -180,16 +168,13 @@ internal IKeyRing GetCurrentKeyRingCore(DateTime utcNow) } catch (Exception ex) { - if (_logger.IsErrorLevelEnabled()) + if (existingCacheableKeyRing != null) + { + _logger.ErrorOccurredWhileRefreshingKeyRing(ex); + } + else { - if (existingCacheableKeyRing != null) - { - _logger.LogError(ex, "An error occurred while refreshing the key ring. Will try again in 2 minutes."); - } - else - { - _logger.LogError(ex, "An error occurred while reading the key ring."); - } + _logger.ErrorOccurredWhileReadingKeyRing(ex); } // Failures that occur while refreshing the keyring are most likely transient, perhaps due to a diff --git a/src/Microsoft.AspNet.DataProtection/KeyManagement/XmlKeyManager.cs b/src/Microsoft.AspNet.DataProtection/KeyManagement/XmlKeyManager.cs index f913b7f6..a137fef2 100644 --- a/src/Microsoft.AspNet.DataProtection/KeyManagement/XmlKeyManager.cs +++ b/src/Microsoft.AspNet.DataProtection/KeyManagement/XmlKeyManager.cs @@ -175,10 +175,7 @@ public IReadOnlyCollection GetAllKeys() else { // Skip unknown elements. - if (_logger.IsWarningLevelEnabled()) - { - _logger.LogWarningF($"Unknown element with name '{element.Name}' found in keyring, skipping."); - } + _logger.UnknownElementWithNameFoundInKeyringSkipping(element.Name); } } @@ -192,17 +189,11 @@ public IReadOnlyCollection GetAllKeys() if (key != null) { key.SetRevoked(); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Marked key {revokedKeyId:B} as revoked in the keyring."); - } + _logger.MarkedKeyAsRevokedInTheKeyring(revokedKeyId); } else { - if (_logger.IsWarningLevelEnabled()) - { - _logger.LogWarningF($"Tried to process revocation of key {revokedKeyId:B}, but no such key was found in keyring. Skipping."); - } + _logger.TriedToProcessRevocationOfKeyButNoSuchKeyWasFound(revokedKeyId); } } } @@ -220,10 +211,7 @@ public IReadOnlyCollection GetAllKeys() if (key.CreationDate < mostRecentMassRevocationDate) { key.SetRevoked(); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Marked key {key.KeyId:B} as revoked in the keyring."); - } + _logger.MarkedKeyAsRevokedInTheKeyring(key.KeyId); } } } @@ -249,10 +237,7 @@ private KeyBase ProcessKeyElement(XElement keyElement) DateTimeOffset activationDate = (DateTimeOffset)keyElement.Element(ActivationDateElementName); DateTimeOffset expirationDate = (DateTimeOffset)keyElement.Element(ExpirationDateElementName); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Found key {keyId:B}."); - } + _logger.FoundKey(keyId); return new DeferredKey( keyId: keyId, @@ -283,20 +268,14 @@ private object ProcessRevocationElement(XElement revocationElement) { // this is a mass revocation of all keys as of the specified revocation date DateTimeOffset massRevocationDate = (DateTimeOffset)revocationElement.Element(RevocationDateElementName); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Found revocation of all keys created prior to {massRevocationDate:u}."); - } + _logger.FoundRevocationOfAllKeysCreatedPriorTo(massRevocationDate); return massRevocationDate; } else { // only one key is being revoked Guid keyId = XmlConvert.ToGuid(keyIdAsString); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Found revocation of key {keyId:B}."); - } + _logger.FoundRevocationOfKey(keyId); return keyId; } } @@ -304,10 +283,7 @@ private object ProcessRevocationElement(XElement revocationElement) { // Any exceptions that occur are fatal - we don't want to continue if we cannot process // revocation information. - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogErrorF(ex, $"An exception occurred while processing the revocation element '{revocationElement}'. Cannot continue keyring processing."); - } + _logger.ExceptionWhileProcessingRevocationElement(revocationElement, ex); throw; } } @@ -321,10 +297,7 @@ public void RevokeAllKeys(DateTimeOffset revocationDate, string reason = null) // ... // - if (_logger.IsInformationLevelEnabled()) - { - _logger.LogInformationF($"Revoking all keys as of {revocationDate:u} for reason '{reason}'."); - } + _logger.RevokingAllKeysAsOfForReason(revocationDate, reason); var revocationElement = new XElement(RevocationElementName, new XAttribute(VersionAttributeName, 1), @@ -350,9 +323,9 @@ public void RevokeKey(Guid keyId, string reason = null) private void TriggerAndResetCacheExpirationToken([CallerMemberName] string opName = null, bool suppressLogging = false) { - if (!suppressLogging && _logger.IsVerboseLevelEnabled()) + if (!suppressLogging) { - _logger.LogVerboseF($"Key cache expiration token triggered by '{opName}' operation."); + _logger.KeyCacheExpirationTokenTriggeredByOperation(opName); } Interlocked.Exchange(ref _cacheExpirationTokenSource, new CancellationTokenSource())?.Cancel(); @@ -365,17 +338,12 @@ private void WriteKeyDeserializationErrorToLog(Exception error, XElement keyElem // log and the raw element to the debug log. This works for our out-of-box XML decryptors since they don't // include sensitive information in the exception message. - if (_logger.IsErrorLevelEnabled()) - { - // write sanitized element - _logger.LogErrorF(error, $"An exception occurred while processing the key element '{keyElement.WithoutChildNodes()}'."); - } + // write sanitized element + _logger.ExceptionWhileProcessingKeyElement(keyElement.WithoutChildNodes(), error); + + // write full element + _logger.AnExceptionOccurredWhileProcessingElementDebug(keyElement, error); - if (_logger.IsDebugLevelEnabled()) - { - // write full element - _logger.LogDebugF(error, $"An exception occurred while processing the key element '{keyElement}'."); - } } IKey IInternalXmlKeyManager.CreateNewKey(Guid keyId, DateTimeOffset creationDate, DateTimeOffset activationDate, DateTimeOffset expirationDate) @@ -389,19 +357,13 @@ IKey IInternalXmlKeyManager.CreateNewKey(Guid keyId, DateTimeOffset creationDate // // - if (_logger.IsInformationLevelEnabled()) - { - _logger.LogInformationF($"Creating key {keyId:B} with creation date {creationDate:u}, activation date {activationDate:u}, and expiration date {expirationDate:u}."); - } + _logger.CreatingKey(keyId, creationDate, activationDate, expirationDate); var newDescriptor = _authenticatedEncryptorConfiguration.CreateNewDescriptor() ?? CryptoUtil.Fail("CreateNewDescriptor returned null."); var descriptorXmlInfo = newDescriptor.ExportToXml(); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Descriptor deserializer type for key {keyId:B} is '{descriptorXmlInfo.DeserializerType.AssemblyQualifiedName}'."); - } + _logger.DescriptorDeserializerTypeForKeyIs(keyId, descriptorXmlInfo.DeserializerType.AssemblyQualifiedName); // build the element var keyElement = new XElement(KeyElementName, @@ -415,23 +377,20 @@ IKey IInternalXmlKeyManager.CreateNewKey(Guid keyId, DateTimeOffset creationDate descriptorXmlInfo.SerializedDescriptorElement)); // If key escrow policy is in effect, write the *unencrypted* key now. - if (_logger.IsVerboseLevelEnabled()) + if (_keyEscrowSink != null) { - if (_keyEscrowSink != null) - { - _logger.LogVerboseF($"Key escrow sink found. Writing key {keyId:B} to escrow."); - } - else - { - _logger.LogVerboseF($"No key escrow sink found. Not writing key {keyId:B} to escrow."); - } + _logger.KeyEscrowSinkFoundWritingKeyToEscrow(keyId); + } + else + { + _logger.NoKeyEscrowSinkFoundNotWritingKeyToEscrow(keyId); } _keyEscrowSink?.Store(keyId, keyElement); // If an XML encryptor has been configured, protect secret key material now. - if (KeyEncryptor == null && _logger.IsWarningLevelEnabled()) + if (KeyEncryptor == null) { - _logger.LogWarningF($"No XML encryptor configured. Key {keyId:B} may be persisted to storage in unencrypted form."); + _logger.NoXMLEncryptorConfiguredKeyMayBePersistedToStorageInUnencryptedForm(keyId); } var possiblyEncryptedKeyElement = KeyEncryptor?.EncryptIfNecessary(keyElement) ?? keyElement; @@ -479,10 +438,7 @@ void IInternalXmlKeyManager.RevokeSingleKey(Guid keyId, DateTimeOffset revocatio // ... // - if (_logger.IsInformationLevelEnabled()) - { - _logger.LogInformationF($"Revoking key {keyId:B} at {revocationDate:u} for reason '{reason}'."); - } + _logger.RevokingKeyForReason(keyId, revocationDate, reason); var revocationElement = new XElement(RevocationElementName, new XAttribute(VersionAttributeName, 1), diff --git a/src/Microsoft.AspNet.DataProtection/LoggingExtensions.cs b/src/Microsoft.AspNet.DataProtection/LoggingExtensions.cs index 2c8a7dd3..509f1568 100644 --- a/src/Microsoft.AspNet.DataProtection/LoggingExtensions.cs +++ b/src/Microsoft.AspNet.DataProtection/LoggingExtensions.cs @@ -3,16 +3,368 @@ using System; using System.Runtime.CompilerServices; -using Microsoft.Extensions.Logging.Internal; +using System.Xml.Linq; +using Microsoft.Win32; namespace Microsoft.Extensions.Logging { /// /// Helpful extension methods on . - /// Methods ending in *F take as a parameter. /// internal static class LoggingExtensions { + private static Action _usingFallbackKeyWithExpirationAsDefaultKey; + + private static Action _usingKeyAsDefaultKey; + + private static Action _openingCNGAlgorithmFromProviderWithHMAC; + + private static Action _openingCNGAlgorithmFromProviderWithChainingModeCBC; + + private static Action _performingUnprotectOperationToKeyWithPurposes; + + private static Action _keyWasNotFoundInTheKeyRingUnprotectOperationCannotProceed; + + private static Action _keyWasRevokedCallerRequestedUnprotectOperationProceedRegardless; + + private static Action _keyWasRevokedUnprotectOperationCannotProceed; + + private static Action _openingCNGAlgorithmFromProviderWithChainingModeGCM; + + private static Action _usingManagedKeyedHashAlgorithm; + + private static Action _usingManagedSymmetricAlgorithm; + + private static Action _keyIsIneligibleToBeTheDefaultKeyBecauseItsMethodFailed; + + private static Action _consideringKeyWithExpirationDateAsDefaultKey; + + private static Action _keyIsNoLongerUnderConsiderationAsDefault; + + private static Action _unknownElementWithNameFoundInKeyringSkipping; + + private static Action _markedKeyAsRevokedInTheKeyring; + + private static Action _triedToProcessRevocationOfKeyButNoSuchKeyWasFound; + + private static Action _foundKey; + + private static Action _foundRevocationOfAllKeysCreatedPriorTo; + + private static Action _foundRevocationOfKey; + + private static Action _exceptionWhileProcessingRevocationElement; + + private static Action _revokingAllKeysAsOfForReason; + + private static Action _keyCacheExpirationTokenTriggeredByOperation; + + private static Action _anExceptionOccurredWhileProcessingTheKeyElement; + + private static Action _anExceptionOccurredWhileProcessingTheKeyElementDebug; + + private static Action _encryptingToWindowsDPAPIForCurrentUserAccount; + + private static Action _encryptingToWindowsDPAPINGUsingProtectionDescriptorRule; + + private static Action _anErrorOccurredWhileEncryptingToX509CertificateWithThumbprint; + + private static Action _encryptingToX509CertificateWithThumbprint; + + private static Action _exceptionOccurredWhileTryingToResolveCertificateWithThumbprint; + + private static Action _performingProtectOperationToKeyWithPurposes; + + private static Action _creatingKey; + + private static Action _descriptorDeserializerTypeForKeyIs; + + private static Action _keyEscrowSinkFoundWritingKeyToEscrow; + + private static Action _noKeyEscrowSinkFoundNotWritingKeyToEscrow; + + private static Action _noXMLEncryptorConfiguredKeyMayBePersistedToStorageInUnencryptedForm; + + private static Action _revokingKeyForReason; + + private static Action _readingDataFromFile; + + private static Action _nameIsNotSafeFileName; + + private static Action _writingDataToFile; + + private static Action _readingDataFromRegistryKeyValue; + + private static Action _nameIsNotSafeRegistryValueName; + + private static Action _decryptingSecretElementUsingWindowsDPAPING; + + private static Action _exceptionOccurredTryingToDecryptElement; + + private static Action _encryptingUsingNullEncryptor; + + private static Action _usingEphemeralDataProtectionProvider; + + private static Action _existingCachedKeyRingIsExpiredRefreshing; + + private static Action _errorOccurredWhileRefreshingKeyRing; + + private static Action _errorOccurredWhileReadingKeyRing; + + private static Action _keyRingDoesNotContainValidDefaultKey; + + private static Action _usingInmemoryRepository; + + private static Action _decryptingSecretElementUsingWindowsDPAPI; + + private static Action _defaultKeyExpirationImminentAndRepository; + + private static Action _repositoryContainsNoViableDefaultKey; + + private static Action _errorOccurredWhileEncryptingToWindowsDPAPI; + + private static Action _encryptingToWindowsDPAPIForLocalMachineAccount; + + private static Action _errorOccurredWhileEncryptingToWindowsDPAPING; + + private static Action _policyResolutionStatesThatANewKeyShouldBeAddedToTheKeyRing; + + static LoggingExtensions() + { + _usingFallbackKeyWithExpirationAsDefaultKey = LoggerMessage.Define( + eventId: 1, + logLevel: LogLevel.Warning, + formatString: "Policy resolution states that a new key should be added to the key ring, but automatic generation of keys is disabled. Using fallback key {KeyId:B} with expiration {ExpirationDate:u} as default key."); + _usingKeyAsDefaultKey = LoggerMessage.Define( + eventId: 2, + logLevel: LogLevel.Verbose, + formatString: "Using key {KeyId:B} as the default key."); + _openingCNGAlgorithmFromProviderWithHMAC = LoggerMessage.Define( + eventId: 3, + logLevel: LogLevel.Verbose, + formatString: "Opening CNG algorithm '{HashAlgorithm}' from provider '{HashAlgorithmProvider}' with HMAC."); + _openingCNGAlgorithmFromProviderWithChainingModeCBC = LoggerMessage.Define( + eventId: 4, + logLevel: LogLevel.Verbose, + formatString: "Opening CNG algorithm '{EncryptionAlgorithm}' from provider '{EncryptionAlgorithmProvider}' with chaining mode CBC."); + _performingUnprotectOperationToKeyWithPurposes = LoggerMessage.Define( + eventId: 5, + logLevel: LogLevel.Debug, + formatString: "Performing unprotect operation to key {KeyId:B} with purposes {Purposes}."); + _keyWasNotFoundInTheKeyRingUnprotectOperationCannotProceed = LoggerMessage.Define( + eventId: 6, + logLevel: LogLevel.Debug, + formatString: "Key {KeyId:B} was not found in the key ring. Unprotect operation cannot proceed."); + _keyWasRevokedCallerRequestedUnprotectOperationProceedRegardless = LoggerMessage.Define( + eventId: 7, + logLevel: LogLevel.Verbose, + formatString: "Key {KeyId:B} was revoked. Caller requested unprotect operation proceed regardless."); + _keyWasRevokedUnprotectOperationCannotProceed = LoggerMessage.Define( + eventId: 8, + logLevel: LogLevel.Verbose, + formatString: "Key {KeyId:B} was revoked. Unprotect operation cannot proceed."); + _openingCNGAlgorithmFromProviderWithChainingModeGCM = LoggerMessage.Define( + eventId: 9, + logLevel: LogLevel.Verbose, + formatString: "Opening CNG algorithm '{EncryptionAlgorithm}' from provider '{EncryptionAlgorithmProvider}' with chaining mode GCM."); + _usingManagedKeyedHashAlgorithm = LoggerMessage.Define( + eventId: 10, + logLevel: LogLevel.Verbose, + formatString: "Using managed keyed hash algorithm '{FullName}'."); + _usingManagedSymmetricAlgorithm = LoggerMessage.Define( + eventId: 11, + logLevel: LogLevel.Verbose, + formatString: "Using managed symmetric algorithm '{FullName}'."); + _keyIsIneligibleToBeTheDefaultKeyBecauseItsMethodFailed = LoggerMessage.Define( + eventId: 12, + logLevel: LogLevel.Warning, + formatString: "Key {KeyId:B} is ineligible to be the default key because its {MethodName} method failed."); + _consideringKeyWithExpirationDateAsDefaultKey = LoggerMessage.Define( + eventId: 13, + logLevel: LogLevel.Verbose, + formatString: "Considering key {KeyId:B} with expiration date {ExpirationDate:u} as default key."); + _keyIsNoLongerUnderConsiderationAsDefault = LoggerMessage.Define( + eventId: 14, + logLevel: LogLevel.Verbose, + formatString: "Key {KeyId:B} is no longer under consideration as default key because it is expired, revoked, or cannot be deciphered."); + _unknownElementWithNameFoundInKeyringSkipping = LoggerMessage.Define( + eventId: 15, + logLevel: LogLevel.Warning, + formatString: "Unknown element with name '{Name}' found in keyring, skipping."); + _markedKeyAsRevokedInTheKeyring = LoggerMessage.Define( + eventId: 16, + logLevel: LogLevel.Verbose, + formatString: "Marked key {KeyId:B} as revoked in the keyring."); + _triedToProcessRevocationOfKeyButNoSuchKeyWasFound = LoggerMessage.Define( + eventId: 17, + logLevel: LogLevel.Warning, + formatString: "Tried to process revocation of key {KeyId:B}, but no such key was found in keyring. Skipping."); + _foundKey = LoggerMessage.Define( + eventId: 18, + logLevel: LogLevel.Verbose, + formatString: "Found key {KeyId:B}."); + _foundRevocationOfAllKeysCreatedPriorTo = LoggerMessage.Define( + eventId: 19, + logLevel: LogLevel.Verbose, + formatString: "Found revocation of all keys created prior to {RevocationDate:u}."); + _foundRevocationOfKey = LoggerMessage.Define( + eventId: 20, + logLevel: LogLevel.Verbose, + formatString: "Found revocation of key {KeyId:B}."); + _exceptionWhileProcessingRevocationElement = LoggerMessage.Define( + eventId: 21, + logLevel: LogLevel.Error, + formatString: "An exception occurred while processing the revocation element '{RevocationElement}'. Cannot continue keyring processing."); + _revokingAllKeysAsOfForReason = LoggerMessage.Define( + eventId: 22, + logLevel: LogLevel.Information, + formatString: "Revoking all keys as of {RevocationDate:u} for reason '{Reason}'."); + _keyCacheExpirationTokenTriggeredByOperation = LoggerMessage.Define( + eventId: 23, + logLevel: LogLevel.Verbose, + formatString: "Key cache expiration token triggered by '{OperationName}' operation."); + _anExceptionOccurredWhileProcessingTheKeyElement = LoggerMessage.Define( + eventId: 24, + logLevel: LogLevel.Error, + formatString: "An exception occurred while processing the key element '{Element}'."); + _anExceptionOccurredWhileProcessingTheKeyElementDebug = LoggerMessage.Define( + eventId: 25, + logLevel: LogLevel.Debug, + formatString: "An exception occurred while processing the key element '{Element}'."); + _encryptingToWindowsDPAPIForCurrentUserAccount = LoggerMessage.Define( + eventId: 26, + logLevel: LogLevel.Verbose, + formatString: "Encrypting to Windows DPAPI for current user account ({Name})."); + _encryptingToWindowsDPAPINGUsingProtectionDescriptorRule = LoggerMessage.Define( + eventId: 27, + logLevel: LogLevel.Verbose, + formatString: "Encrypting to Windows DPAPI-NG using protection descriptor rule '{DescriptorRule}'."); + _anErrorOccurredWhileEncryptingToX509CertificateWithThumbprint = LoggerMessage.Define( + eventId: 28, + logLevel: LogLevel.Error, + formatString: "An error occurred while encrypting to X.509 certificate with thumbprint '{Thumbprint}'."); + _encryptingToX509CertificateWithThumbprint = LoggerMessage.Define( + eventId: 29, + logLevel: LogLevel.Verbose, + formatString: "Encrypting to X.509 certificate with thumbprint '{Thumbprint}'."); + _exceptionOccurredWhileTryingToResolveCertificateWithThumbprint = LoggerMessage.Define( + eventId: 30, + logLevel: LogLevel.Error, + formatString: "An exception occurred while trying to resolve certificate with thumbprint '{Thumbprint}'."); + _performingProtectOperationToKeyWithPurposes = LoggerMessage.Define( + eventId: 31, + logLevel: LogLevel.Debug, + formatString: "Performing protect operation to key {KeyId:B} with purposes {Purposes}."); + _descriptorDeserializerTypeForKeyIs = LoggerMessage.Define( + eventId: 32, + logLevel: LogLevel.Verbose, + formatString: "Descriptor deserializer type for key {KeyId:B} is '{AssemblyQualifiedName}'."); + _keyEscrowSinkFoundWritingKeyToEscrow = LoggerMessage.Define( + eventId: 33, + logLevel: LogLevel.Verbose, + formatString: "Key escrow sink found. Writing key {KeyId:B} to escrow."); + _noKeyEscrowSinkFoundNotWritingKeyToEscrow = LoggerMessage.Define( + eventId: 34, + logLevel: LogLevel.Verbose, + formatString: "No key escrow sink found. Not writing key {KeyId:B} to escrow."); + _noXMLEncryptorConfiguredKeyMayBePersistedToStorageInUnencryptedForm = LoggerMessage.Define( + eventId: 35, + logLevel: LogLevel.Warning, + formatString: "No XML encryptor configured. Key {KeyId:B} may be persisted to storage in unencrypted form."); + _revokingKeyForReason = LoggerMessage.Define( + eventId: 36, + logLevel: LogLevel.Information, + formatString: "Revoking key {KeyId:B} at {RevocationDate:u} for reason '{Reason}'."); + _readingDataFromFile = LoggerMessage.Define( + eventId: 37, + logLevel: LogLevel.Verbose, + formatString: "Reading data from file '{FullPath}'."); + _nameIsNotSafeFileName = LoggerMessage.Define( + eventId: 38, + logLevel: LogLevel.Verbose, + formatString: "The name '{FriendlyName}' is not a safe file name, using '{NewFriendlyName}' instead."); + _writingDataToFile = LoggerMessage.Define( + eventId: 39, + logLevel: LogLevel.Information, + formatString: "Writing data to file '{FileName}'."); + _readingDataFromRegistryKeyValue = LoggerMessage.Define( + eventId: 40, + logLevel: LogLevel.Verbose, + formatString: "Reading data from registry key '{RegistryKeyName}', value '{Value}'."); + _nameIsNotSafeRegistryValueName = LoggerMessage.Define( + eventId: 41, + logLevel: LogLevel.Verbose, + formatString: "The name '{FriendlyName}' is not a safe registry value name, using '{NewFriendlyName}' instead."); + _decryptingSecretElementUsingWindowsDPAPING = LoggerMessage.Define( + eventId: 42, + logLevel: LogLevel.Verbose, + formatString: "Decrypting secret element using Windows DPAPI-NG with protection descriptor rule '{DescriptorRule}'."); + _exceptionOccurredTryingToDecryptElement = LoggerMessage.Define( + eventId: 43, + logLevel: LogLevel.Error, + formatString: "An exception occurred while trying to decrypt the element."); + _encryptingUsingNullEncryptor = LoggerMessage.Define( + eventId: 44, + logLevel: LogLevel.Warning, + formatString: "Encrypting using a null encryptor; secret information isn't being protected."); + _usingEphemeralDataProtectionProvider = LoggerMessage.Define( + eventId: 45, + logLevel: LogLevel.Warning, + formatString: "Using ephemeral data protection provider. Payloads will be undecipherable upon application shutdown."); + _existingCachedKeyRingIsExpiredRefreshing = LoggerMessage.Define( + eventId: 46, + logLevel: LogLevel.Verbose, + formatString: "Existing cached key ring is expired. Refreshing."); + _errorOccurredWhileRefreshingKeyRing = LoggerMessage.Define( + eventId: 47, + logLevel: LogLevel.Error, + formatString: "An error occurred while refreshing the key ring. Will try again in 2 minutes."); + _errorOccurredWhileReadingKeyRing = LoggerMessage.Define( + eventId: 48, + logLevel: LogLevel.Error, + formatString: "An error occurred while reading the key ring."); + _keyRingDoesNotContainValidDefaultKey = LoggerMessage.Define( + eventId: 49, + logLevel: LogLevel.Error, + formatString: "The key ring does not contain a valid default key, and the key manager is configured with auto-generation of keys disabled."); + _usingInmemoryRepository = LoggerMessage.Define( + eventId: 50, + logLevel: LogLevel.Warning, + formatString: "Using an in-memory repository. Keys will not be persisted to storage."); + _decryptingSecretElementUsingWindowsDPAPI = LoggerMessage.Define( + eventId: 51, + logLevel: LogLevel.Verbose, + formatString: "Decrypting secret element using Windows DPAPI."); + _defaultKeyExpirationImminentAndRepository = LoggerMessage.Define( + eventId: 52, + logLevel: LogLevel.Verbose, + formatString: "Default key expiration imminent and repository contains no viable successor. Caller should generate a successor."); + _repositoryContainsNoViableDefaultKey = LoggerMessage.Define( + eventId: 53, + logLevel: LogLevel.Verbose, + formatString: "Repository contains no viable default key. Caller should generate a key with immediate activation."); + _errorOccurredWhileEncryptingToWindowsDPAPI = LoggerMessage.Define( + eventId: 54, + logLevel: LogLevel.Error, + formatString: "An error occurred while encrypting to Windows DPAPI."); + _encryptingToWindowsDPAPIForLocalMachineAccount = LoggerMessage.Define( + eventId: 55, + logLevel: LogLevel.Verbose, + formatString: "Encrypting to Windows DPAPI for local machine account."); + _errorOccurredWhileEncryptingToWindowsDPAPING = LoggerMessage.Define( + eventId: 56, + logLevel: LogLevel.Error, + formatString: "An error occurred while encrypting to Windows DPAPI-NG."); + _policyResolutionStatesThatANewKeyShouldBeAddedToTheKeyRing = LoggerMessage.Define( + eventId: 57, + logLevel: LogLevel.Verbose, + formatString: "Policy resolution states that a new key should be added to the key ring."); + _creatingKey = LoggerMessage.Define( + eventId: 58, + logLevel: LogLevel.Information, + formatString: "Creating key {KeyId:B} with creation date {CreationDate:u}, activation date {ActivationDate:u}, and expiration date {ExpirationDate:u}."); + } + /// /// Returns a value stating whether the 'debug' log level is enabled. /// Returns false if the logger instance is null. @@ -69,44 +421,294 @@ private static bool IsLogLevelEnabledCore(ILogger logger, LogLevel level) return (logger != null && logger.IsEnabled(level)); } - public static void LogDebugF(this ILogger logger, FormattableString message) + public static void UsingFallbackKeyWithExpirationAsDefaultKey(this ILogger logger, Guid keyId, DateTimeOffset expirationDate) + { + _usingFallbackKeyWithExpirationAsDefaultKey(logger, keyId, expirationDate, null); + } + + public static void UsingKeyAsDefaultKey(this ILogger logger, Guid keyId) + { + _usingKeyAsDefaultKey(logger, keyId, null); + } + + public static void OpeningCNGAlgorithmFromProviderWithHMAC(this ILogger logger, string hashAlgorithm, string hashAlgorithmProvider) + { + _openingCNGAlgorithmFromProviderWithHMAC(logger, hashAlgorithm, hashAlgorithmProvider, null); + } + + public static void OpeningCNGAlgorithmFromProviderWithChainingModeCBC(this ILogger logger, string encryptionAlgorithm, string encryptionAlgorithmProvider) + { + _openingCNGAlgorithmFromProviderWithChainingModeCBC(logger, encryptionAlgorithm, encryptionAlgorithmProvider, null); + } + + public static void PerformingUnprotectOperationToKeyWithPurposes(this ILogger logger, Guid keyIdFromPayload, string p0) + { + _performingUnprotectOperationToKeyWithPurposes(logger, keyIdFromPayload, p0, null); + } + + public static void KeyWasNotFoundInTheKeyRingUnprotectOperationCannotProceed(this ILogger logger, Guid keyIdFromPayload) + { + _keyWasNotFoundInTheKeyRingUnprotectOperationCannotProceed(logger, keyIdFromPayload, null); + } + + public static void KeyWasRevokedCallerRequestedUnprotectOperationProceedRegardless(this ILogger logger, Guid keyIdFromPayload) + { + _keyWasRevokedCallerRequestedUnprotectOperationProceedRegardless(logger, keyIdFromPayload, null); + } + + public static void KeyWasRevokedUnprotectOperationCannotProceed(this ILogger logger, Guid keyIdFromPayload) + { + _keyWasRevokedUnprotectOperationCannotProceed(logger, keyIdFromPayload, null); + } + + public static void OpeningCNGAlgorithmFromProviderWithChainingModeGCM(this ILogger logger, string encryptionAlgorithm, string encryptionAlgorithmProvider) + { + _openingCNGAlgorithmFromProviderWithChainingModeGCM(logger, encryptionAlgorithm, encryptionAlgorithmProvider, null); + } + + public static void UsingManagedKeyedHashAlgorithm(this ILogger logger, string fullName) + { + _usingManagedKeyedHashAlgorithm(logger, fullName, null); + } + + public static void UsingManagedSymmetricAlgorithm(this ILogger logger, string fullName) + { + _usingManagedSymmetricAlgorithm(logger, fullName, null); + } + + public static void KeyIsIneligibleToBeTheDefaultKeyBecauseItsMethodFailed(this ILogger logger, Guid keyId, string p0, Exception exception) + { + _keyIsIneligibleToBeTheDefaultKeyBecauseItsMethodFailed(logger, keyId, p0, exception); + } + + public static void ConsideringKeyWithExpirationDateAsDefaultKey(this ILogger logger, Guid keyId, DateTimeOffset expirationDate) + { + _consideringKeyWithExpirationDateAsDefaultKey(logger, keyId, expirationDate, null); + } + + public static void KeyIsNoLongerUnderConsiderationAsDefault(this ILogger logger, Guid keyId) + { + _keyIsNoLongerUnderConsiderationAsDefault(logger, keyId, null); + } + + public static void UnknownElementWithNameFoundInKeyringSkipping(this ILogger logger, XName name) + { + _unknownElementWithNameFoundInKeyringSkipping(logger, name, null); + } + + public static void MarkedKeyAsRevokedInTheKeyring(this ILogger logger, Guid revokedKeyId) + { + _markedKeyAsRevokedInTheKeyring(logger, revokedKeyId, null); + } + + public static void TriedToProcessRevocationOfKeyButNoSuchKeyWasFound(this ILogger logger, Guid revokedKeyId) + { + _triedToProcessRevocationOfKeyButNoSuchKeyWasFound(logger, revokedKeyId, null); + } + + public static void FoundKey(this ILogger logger, Guid keyId) + { + _foundKey(logger, keyId, null); + } + + public static void FoundRevocationOfAllKeysCreatedPriorTo(this ILogger logger, DateTimeOffset massRevocationDate) + { + _foundRevocationOfAllKeysCreatedPriorTo(logger, massRevocationDate, null); + } + + public static void FoundRevocationOfKey(this ILogger logger, Guid keyId) + { + _foundRevocationOfKey(logger, keyId, null); + } + + public static void ExceptionWhileProcessingRevocationElement(this ILogger logger, XElement revocationElement, Exception exception) + { + _exceptionWhileProcessingRevocationElement(logger, revocationElement, exception); + } + + public static void RevokingAllKeysAsOfForReason(this ILogger logger, DateTimeOffset revocationDate, string reason) + { + _revokingAllKeysAsOfForReason(logger, revocationDate, reason, null); + } + + public static void KeyCacheExpirationTokenTriggeredByOperation(this ILogger logger, string opName) + { + _keyCacheExpirationTokenTriggeredByOperation(logger, opName, null); + } + + public static void ExceptionWhileProcessingKeyElement(this ILogger logger, XElement keyElement, Exception exception) + { + _anExceptionOccurredWhileProcessingTheKeyElement(logger, keyElement, exception); + } + + public static void AnExceptionOccurredWhileProcessingElementDebug(this ILogger logger, XElement keyElement, Exception exception) + { + _anExceptionOccurredWhileProcessingTheKeyElementDebug(logger, keyElement, exception); + } + + public static void EncryptingToWindowsDPAPIForCurrentUserAccount(this ILogger logger, string name) + { + _encryptingToWindowsDPAPIForCurrentUserAccount(logger, name, null); + } + + public static void AnErrorOccurredWhileEncryptingToX509CertificateWithThumbprint(this ILogger logger, string thumbprint, Exception exception) + { + _anErrorOccurredWhileEncryptingToX509CertificateWithThumbprint(logger, thumbprint, exception); + } + + public static void EncryptingToX509CertificateWithThumbprint(this ILogger logger, string thumbprint) + { + _encryptingToX509CertificateWithThumbprint(logger, thumbprint, null); + } + + public static void ExceptionWhileTryingToResolveCertificateWithThumbprint(this ILogger logger, string thumbprint, Exception exception) + { + _exceptionOccurredWhileTryingToResolveCertificateWithThumbprint(logger, thumbprint, exception); + } + + public static void PerformingProtectOperationToKeyWithPurposes(this ILogger logger, Guid defaultKeyId, string p0) + { + _performingProtectOperationToKeyWithPurposes(logger, defaultKeyId, p0, null); + } + + public static void DescriptorDeserializerTypeForKeyIs(this ILogger logger, Guid keyId, string assemblyQualifiedName) + { + _descriptorDeserializerTypeForKeyIs(logger, keyId, assemblyQualifiedName, null); + } + + public static void KeyEscrowSinkFoundWritingKeyToEscrow(this ILogger logger, Guid keyId) + { + _keyEscrowSinkFoundWritingKeyToEscrow(logger, keyId, null); + } + + public static void NoKeyEscrowSinkFoundNotWritingKeyToEscrow(this ILogger logger, Guid keyId) + { + _noKeyEscrowSinkFoundNotWritingKeyToEscrow(logger, keyId, null); + } + + public static void NoXMLEncryptorConfiguredKeyMayBePersistedToStorageInUnencryptedForm(this ILogger logger, Guid keyId) + { + _noXMLEncryptorConfiguredKeyMayBePersistedToStorageInUnencryptedForm(logger, keyId, null); + } + + public static void RevokingKeyForReason(this ILogger logger, Guid keyId, DateTimeOffset revocationDate, string reason) + { + _revokingKeyForReason(logger, keyId, revocationDate, reason, null); + } + + public static void ReadingDataFromFile(this ILogger logger, string fullPath) + { + _readingDataFromFile(logger, fullPath, null); + } + + public static void NameIsNotSafeFileName(this ILogger logger, string friendlyName, string newFriendlyName) + { + _nameIsNotSafeFileName(logger, friendlyName, newFriendlyName, null); + } + + public static void WritingDataToFile(this ILogger logger, string finalFilename) + { + _writingDataToFile(logger, finalFilename, null); + } + + public static void ReadingDataFromRegistryKeyValue(this ILogger logger, RegistryKey regKey, string valueName) + { + _readingDataFromRegistryKeyValue(logger, regKey, valueName, null); + } + + public static void NameIsNotSafeRegistryValueName(this ILogger logger, string friendlyName, string newFriendlyName) + { + _nameIsNotSafeRegistryValueName(logger, friendlyName, newFriendlyName, null); + } + + public static void DecryptingSecretElementUsingWindowsDPAPING(this ILogger logger, string protectionDescriptorRule) + { + _decryptingSecretElementUsingWindowsDPAPING(logger, protectionDescriptorRule, null); + } + + public static void EncryptingToWindowsDPAPINGUsingProtectionDescriptorRule(this ILogger logger, string protectionDescriptorRuleString) + { + _encryptingToWindowsDPAPINGUsingProtectionDescriptorRule(logger, protectionDescriptorRuleString, null); + } + + public static void ExceptionOccurredTryingToDecryptElement(this ILogger logger, Exception exception) + { + _exceptionOccurredTryingToDecryptElement(logger, exception); + } + + public static void EncryptingUsingNullEncryptor(this ILogger logger) + { + _encryptingUsingNullEncryptor(logger, null); + } + + public static void UsingEphemeralDataProtectionProvider(this ILogger logger) + { + _usingEphemeralDataProtectionProvider(logger, null); + } + + public static void ExistingCachedKeyRingIsExpired(this ILogger logger) + { + _existingCachedKeyRingIsExpiredRefreshing(logger, null); + } + + public static void ErrorOccurredWhileRefreshingKeyRing(this ILogger logger, Exception exception) + { + _errorOccurredWhileRefreshingKeyRing(logger, exception); + } + + public static void ErrorOccurredWhileReadingKeyRing(this ILogger logger, Exception exception) + { + _errorOccurredWhileReadingKeyRing(logger, exception); + } + + public static void KeyRingDoesNotContainValidDefaultKey(this ILogger logger) + { + _keyRingDoesNotContainValidDefaultKey(logger, null); + } + + public static void UsingInmemoryRepository(this ILogger logger) + { + _usingInmemoryRepository(logger, null); + } + + public static void DecryptingSecretElementUsingWindowsDPAPI(this ILogger logger) { - logger.LogDebug(message.Format, message.GetArguments()); + _decryptingSecretElementUsingWindowsDPAPI(logger, null); } - public static void LogDebugF(this ILogger logger, Exception error, FormattableString message) + public static void DefaultKeyExpirationImminentAndRepository(this ILogger logger) { - logger.LogDebug(new FormattedLogValues(message.Format, message.GetArguments()), error); + _defaultKeyExpirationImminentAndRepository(logger, null); } - public static void LogError(this ILogger logger, Exception error, string message) + public static void RepositoryContainsNoViableDefaultKey(this ILogger logger) { - logger.LogError(message, error); + _repositoryContainsNoViableDefaultKey(logger, null); } - public static void LogErrorF(this ILogger logger, Exception error, FormattableString message) + public static void ErrorOccurredWhileEncryptingToWindowsDPAPI(this ILogger logger, Exception exception) { - logger.LogError(new FormattedLogValues(message.Format, message.GetArguments()), error); + _errorOccurredWhileEncryptingToWindowsDPAPI(logger, exception); } - public static void LogInformationF(this ILogger logger, FormattableString message) + public static void EncryptingToWindowsDPAPIForLocalMachineAccount(this ILogger logger) { - logger.LogInformation(message.Format, message.GetArguments()); + _encryptingToWindowsDPAPIForLocalMachineAccount(logger, null); } - public static void LogVerboseF(this ILogger logger, FormattableString message) + public static void ErrorOccurredWhileEncryptingToWindowsDPAPING(this ILogger logger, Exception exception) { - logger.LogVerbose(message.Format, message.GetArguments()); + _errorOccurredWhileEncryptingToWindowsDPAPING(logger, exception); } - public static void LogWarningF(this ILogger logger, FormattableString message) + public static void PolicyResolutionStatesThatANewKeyShouldBeAddedToTheKeyRing(this ILogger logger) { - logger.LogWarning(message.Format, message.GetArguments()); + _policyResolutionStatesThatANewKeyShouldBeAddedToTheKeyRing(logger, null); } - public static void LogWarningF(this ILogger logger, Exception error, FormattableString message) + public static void CreatingKey(this ILogger logger, Guid keyId, DateTimeOffset creationDate, DateTimeOffset activationDate, DateTimeOffset expirationDate) { - logger.LogWarning(new FormattedLogValues(message.Format, message.GetArguments()), error); + _creatingKey(logger, keyId, creationDate, activationDate, expirationDate, null); } } -} +} \ No newline at end of file diff --git a/src/Microsoft.AspNet.DataProtection/Repositories/EphemeralXmlRepository.cs b/src/Microsoft.AspNet.DataProtection/Repositories/EphemeralXmlRepository.cs index d1baa63b..1852bafa 100644 --- a/src/Microsoft.AspNet.DataProtection/Repositories/EphemeralXmlRepository.cs +++ b/src/Microsoft.AspNet.DataProtection/Repositories/EphemeralXmlRepository.cs @@ -20,10 +20,7 @@ internal class EphemeralXmlRepository : IXmlRepository public EphemeralXmlRepository(IServiceProvider services) { var logger = services?.GetLogger(); - if (logger.IsWarningLevelEnabled()) - { - logger.LogWarning("Using an in-memory repository. Keys will not be persisted to storage."); - } + logger.UsingInmemoryRepository(); } public virtual IReadOnlyCollection GetAllElements() diff --git a/src/Microsoft.AspNet.DataProtection/Repositories/FileSystemXmlRepository.cs b/src/Microsoft.AspNet.DataProtection/Repositories/FileSystemXmlRepository.cs index 3cc94174..84e46b24 100644 --- a/src/Microsoft.AspNet.DataProtection/Repositories/FileSystemXmlRepository.cs +++ b/src/Microsoft.AspNet.DataProtection/Repositories/FileSystemXmlRepository.cs @@ -185,10 +185,7 @@ private static bool IsSafeFilename(string filename) private XElement ReadElementFromFile(string fullPath) { - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Reading data from file '{fullPath}'."); - } + _logger.ReadingDataFromFile(fullPath); using (var fileStream = File.OpenRead(fullPath)) { @@ -206,10 +203,7 @@ public virtual void StoreElement(XElement element, string friendlyName) if (!IsSafeFilename(friendlyName)) { string newFriendlyName = Guid.NewGuid().ToString(); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"The name '{friendlyName}' is not a safe file name, using '{newFriendlyName}' instead."); - } + _logger.NameIsNotSafeFileName(friendlyName, newFriendlyName); friendlyName = newFriendlyName; } @@ -235,10 +229,7 @@ private void StoreElementCore(XElement element, string filename) // Once the file has been fully written, perform the rename. // Renames are atomic operations on the file systems we support. - if (_logger.IsInformationLevelEnabled()) - { - _logger.LogInformationF($"Writing data to file '{finalFilename}'."); - } + _logger.WritingDataToFile(finalFilename); File.Move(tempFilename, finalFilename); } finally diff --git a/src/Microsoft.AspNet.DataProtection/Repositories/RegistryXmlRepository.cs b/src/Microsoft.AspNet.DataProtection/Repositories/RegistryXmlRepository.cs index b880a12a..baed19aa 100644 --- a/src/Microsoft.AspNet.DataProtection/Repositories/RegistryXmlRepository.cs +++ b/src/Microsoft.AspNet.DataProtection/Repositories/RegistryXmlRepository.cs @@ -140,10 +140,7 @@ private static bool IsSafeRegistryValueName(string filename) private XElement ReadElementFromRegKey(RegistryKey regKey, string valueName) { - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Reading data from registry key '{regKey}', value '{valueName}'."); - } + _logger.ReadingDataFromRegistryKeyValue(regKey, valueName); string data = regKey.GetValue(valueName) as string; return (!String.IsNullOrEmpty(data)) ? XElement.Parse(data) : null; @@ -159,10 +156,7 @@ public virtual void StoreElement(XElement element, string friendlyName) if (!IsSafeRegistryValueName(friendlyName)) { string newFriendlyName = Guid.NewGuid().ToString(); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"The name '{friendlyName}' is not a safe registry value name, using '{newFriendlyName}' instead."); - } + _logger.NameIsNotSafeRegistryValueName(friendlyName, newFriendlyName); friendlyName = newFriendlyName; } diff --git a/src/Microsoft.AspNet.DataProtection/XmlEncryption/CertificateXmlEncryptor.cs b/src/Microsoft.AspNet.DataProtection/XmlEncryption/CertificateXmlEncryptor.cs index 5cdfc505..a2e70040 100644 --- a/src/Microsoft.AspNet.DataProtection/XmlEncryption/CertificateXmlEncryptor.cs +++ b/src/Microsoft.AspNet.DataProtection/XmlEncryption/CertificateXmlEncryptor.cs @@ -149,10 +149,8 @@ private Func CreateCertFactory(string thumbprint, ICertificate } catch (Exception ex) { - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogErrorF(ex, $"An exception occurred while trying to resolve certificate with thumbprint '{thumbprint}'."); - } + _logger.ExceptionWhileTryingToResolveCertificateWithThumbprint(thumbprint, ex); + throw; } }; @@ -163,10 +161,7 @@ EncryptedData IInternalCertificateXmlEncryptor.PerformEncryption(EncryptedXml en var cert = _certFactory() ?? CryptoUtil.Fail("Cert factory returned null."); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Encrypting to X.509 certificate with thumbprint '{cert.Thumbprint}'."); - } + _logger.EncryptingToX509CertificateWithThumbprint(cert.Thumbprint); try { @@ -174,10 +169,7 @@ EncryptedData IInternalCertificateXmlEncryptor.PerformEncryption(EncryptedXml en } catch (Exception ex) { - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogErrorF(ex, $"An error occurred while encrypting to X.509 certificate with thumbprint '{cert.Thumbprint}'."); - } + _logger.AnErrorOccurredWhileEncryptingToX509CertificateWithThumbprint(cert.Thumbprint, ex); throw; } } diff --git a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlDecryptor.cs b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlDecryptor.cs index d451373e..c71b0dd2 100644 --- a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlDecryptor.cs +++ b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlDecryptor.cs @@ -72,7 +72,7 @@ public XElement Decrypt(XElement encryptedElement) // swallow all errors - it's just a log protectionDescriptorRule = null; } - _logger.LogVerboseF($"Decrypting secret element using Windows DPAPI-NG with protection descriptor rule '{protectionDescriptorRule}'."); + _logger.DecryptingSecretElementUsingWindowsDPAPING(protectionDescriptorRule); } using (Secret secret = DpapiSecretSerializerHelper.UnprotectWithDpapiNG(protectedSecret)) @@ -84,10 +84,7 @@ public XElement Decrypt(XElement encryptedElement) { // It's OK for us to log the error, as we control the exception, and it doesn't contain // sensitive information. - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogError(ex, "An exception occurred while trying to decrypt the element."); - } + _logger.ExceptionOccurredTryingToDecryptElement(ex); throw; } } diff --git a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlEncryptor.cs b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlEncryptor.cs index e2c6ee8e..6c2b7182 100644 --- a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlEncryptor.cs +++ b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiNGXmlEncryptor.cs @@ -73,10 +73,7 @@ public EncryptedXmlInfo Encrypt(XElement plaintextElement) } string protectionDescriptorRuleString = _protectionDescriptorHandle.GetProtectionDescriptorRuleString(); - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerboseF($"Encrypting to Windows DPAPI-NG using protection descriptor rule '{protectionDescriptorRuleString}'."); - } + _logger.EncryptingToWindowsDPAPINGUsingProtectionDescriptorRule(protectionDescriptorRuleString); // Convert the XML element to a binary secret so that it can be run through DPAPI byte[] cngDpapiEncryptedData; @@ -89,10 +86,7 @@ public EncryptedXmlInfo Encrypt(XElement plaintextElement) } catch (Exception ex) { - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogError(ex, "An error occurred while encrypting to Windows DPAPI-NG."); - } + _logger.ErrorOccurredWhileEncryptingToWindowsDPAPING(ex); throw; } diff --git a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlDecryptor.cs b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlDecryptor.cs index ad59ab82..fcdf952d 100644 --- a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlDecryptor.cs +++ b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlDecryptor.cs @@ -48,10 +48,7 @@ public XElement Decrypt(XElement encryptedElement) throw new ArgumentNullException(nameof(encryptedElement)); } - if (_logger.IsVerboseLevelEnabled()) - { - _logger.LogVerbose("Decrypting secret element using Windows DPAPI."); - } + _logger.DecryptingSecretElementUsingWindowsDPAPI(); try { @@ -70,10 +67,7 @@ public XElement Decrypt(XElement encryptedElement) { // It's OK for us to log the error, as we control the exception, and it doesn't contain // sensitive information. - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogError(ex, "An exception occurred while trying to decrypt the element."); - } + _logger.AnExceptionOccurredWhileTryingToDecryptElement(ex); throw; } } diff --git a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlEncryptor.cs b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlEncryptor.cs index c1726eb7..192644d8 100644 --- a/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlEncryptor.cs +++ b/src/Microsoft.AspNet.DataProtection/XmlEncryption/DpapiXmlEncryptor.cs @@ -60,17 +60,13 @@ public EncryptedXmlInfo Encrypt(XElement plaintextElement) { throw new ArgumentNullException(nameof(plaintextElement)); } - - if (_logger.IsVerboseLevelEnabled()) + if (_protectToLocalMachine) { - if (_protectToLocalMachine) - { - _logger.LogVerbose("Encrypting to Windows DPAPI for local machine account."); - } - else - { - _logger.LogVerboseF($"Encrypting to Windows DPAPI for current user account ({WindowsIdentity.GetCurrent().Name})."); - } + _logger.EncryptingToWindowsDPAPIForLocalMachineAccount(); + } + else + { + _logger.EncryptingToWindowsDPAPIForCurrentUserAccount(WindowsIdentity.GetCurrent().Name); } // Convert the XML element to a binary secret so that it can be run through DPAPI @@ -84,10 +80,7 @@ public EncryptedXmlInfo Encrypt(XElement plaintextElement) } catch (Exception ex) { - if (_logger.IsErrorLevelEnabled()) - { - _logger.LogError(ex, "An error occurred while encrypting to Windows DPAPI."); - } + _logger.ErrorOccurredWhileEncryptingToWindowsDPAPI(ex); throw; } diff --git a/src/Microsoft.AspNet.DataProtection/XmlEncryption/NullXmlEncryptor.cs b/src/Microsoft.AspNet.DataProtection/XmlEncryption/NullXmlEncryptor.cs index fd3cc01f..5eb4aae2 100644 --- a/src/Microsoft.AspNet.DataProtection/XmlEncryption/NullXmlEncryptor.cs +++ b/src/Microsoft.AspNet.DataProtection/XmlEncryption/NullXmlEncryptor.cs @@ -48,10 +48,7 @@ public EncryptedXmlInfo Encrypt(XElement plaintextElement) throw new ArgumentNullException(nameof(plaintextElement)); } - if (_logger.IsWarningLevelEnabled()) - { - _logger.LogWarning("Encrypting using a null encryptor; secret information isn't being protected."); - } + _logger.EncryptingUsingNullEncryptor(); // //