diff --git a/src/AWS/Orleans.Clustering.DynamoDB/Membership/DynamoDBMembershipTable.cs b/src/AWS/Orleans.Clustering.DynamoDB/Membership/DynamoDBMembershipTable.cs index 664934d22ff..ea12cb068a3 100644 --- a/src/AWS/Orleans.Clustering.DynamoDB/Membership/DynamoDBMembershipTable.cs +++ b/src/AWS/Orleans.Clustering.DynamoDB/Membership/DynamoDBMembershipTable.cs @@ -15,7 +15,7 @@ namespace Orleans.Clustering.DynamoDB { - internal class DynamoDBMembershipTable : IMembershipTable + internal partial class DynamoDBMembershipTable : IMembershipTable { private static readonly TableVersion NotFoundTableVersion = new TableVersion(0, "0"); @@ -52,7 +52,7 @@ public async Task InitializeMembershipTable(bool tryInitTableVersion) this.options.CreateIfNotExists, this.options.UpdateIfExists); - logger.LogInformation((int)ErrorCode.MembershipBase, "Initializing AWS DynamoDB Membership Table"); + LogInformationInitializingMembershipTable(); await storage.InitializeTable(this.options.TableName, new List { @@ -72,7 +72,7 @@ await storage.InitializeTable(this.options.TableName, { // ignore return value, since we don't care if I inserted it or not, as long as it is in there. bool created = await TryCreateTableVersionEntryAsync(); - if(created) logger.LogInformation("Created new table version row."); + if (created) LogInformationCreatedNewTableVersionRow(); } } @@ -158,12 +158,7 @@ public async Task DeleteMembershipTableEntries(string clusterId) } catch (Exception exc) { - this.logger.LogError( - (int)ErrorCode.MembershipBase, - exc, - "Unable to delete membership records on table {TableName} for ClusterId {ClusterId}", - this.options.TableName, - clusterId); + LogErrorUnableToDeleteMembershipRecords(exc, this.options.TableName, clusterId); throw; } } @@ -188,17 +183,12 @@ public async Task ReadRow(SiloAddress siloAddress) new[] {siloEntryKeys, versionEntryKeys}, fields => new SiloInstanceRecord(fields)); MembershipTableData data = Convert(entries.ToList()); - if (this.logger.IsEnabled(LogLevel.Trace)) this.logger.LogTrace("Read my entry {SiloAddress} Table: {TableData}", siloAddress.ToString(), data.ToString()); + LogTraceReadMyEntry(siloAddress, data); return data; } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - exc, - "Intermediate error reading silo entry for key {SiloAddress} from the table {TableName}", - siloAddress.ToString(), - this.options.TableName); + LogWarningIntermediateErrorReadingSiloEntry(exc, siloAddress, this.options.TableName); throw; } } @@ -225,23 +215,19 @@ public async Task ReadAll() if (records.Exists(record => record.MembershipVersion > versionRow.MembershipVersion)) { - this.logger.LogWarning((int)ErrorCode.MembershipBase, "Found an inconsistency while reading all silo entries"); + LogWarningFoundInconsistencyReadingAllSiloEntries(); //not expecting this to hit often, but if it does, should put in a limit return await this.ReadAll(); } MembershipTableData data = Convert(records); - if (this.logger.IsEnabled(LogLevel.Trace)) this.logger.LogTrace("ReadAll Table {Table}", data.ToString()); + LogTraceReadAllTable(data); return data; } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - exc, - "Intermediate error reading all silo entries {TableName}.", - options.TableName); + LogWarningIntermediateErrorReadingAllSiloEntries(exc, options.TableName); throw; } } @@ -250,16 +236,12 @@ public async Task InsertRow(MembershipEntry entry, TableVersion tableVersi { try { - if (this.logger.IsEnabled(LogLevel.Debug)) this.logger.LogDebug("InsertRow entry = {Entry}", entry.ToString()); + LogDebugInsertRow(entry); var tableEntry = Convert(entry, tableVersion); if (!TryCreateTableVersionRecord(tableVersion.Version, tableVersion.VersionEtag, out var versionEntry)) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - "Insert failed. Invalid ETag value. Will retry. Entry {Entry}, eTag {ETag}", - entry.ToString(), - tableVersion.VersionEtag); + LogWarningInsertFailedInvalidETag(entry, tableVersion.VersionEtag); return false; } @@ -298,10 +280,7 @@ public async Task InsertRow(MembershipEntry entry, TableVersion tableVersi if (canceledException.Message.Contains("ConditionalCheckFailed")) //not a good way to check for this currently { result = false; - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - "Insert failed due to contention on the table. Will retry. Entry {Entry}", - entry.ToString()); + LogWarningInsertFailedDueToContention(entry); } else { @@ -313,12 +292,7 @@ public async Task InsertRow(MembershipEntry entry, TableVersion tableVersi } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - exc, - "Intermediate error inserting entry {Entry} to the table {TableName}.", - entry.ToString(), - this.options.TableName); + LogWarningIntermediateErrorInsertingEntry(exc, entry, this.options.TableName); throw; } } @@ -327,15 +301,11 @@ public async Task UpdateRow(MembershipEntry entry, string etag, TableVersi { try { - if (this.logger.IsEnabled(LogLevel.Debug)) this.logger.LogDebug("UpdateRow entry = {Entry}, etag = {}", entry.ToString(), etag); + LogDebugUpdateRow(entry, etag); var siloEntry = Convert(entry, tableVersion); if (!int.TryParse(etag, out var currentEtag)) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - "Update failed. Invalid ETag value. Will retry. Entry {Entry}, eTag {ETag}", - entry.ToString(), - etag); + LogWarningUpdateFailedInvalidETag(entry, etag); return false; } @@ -343,11 +313,7 @@ public async Task UpdateRow(MembershipEntry entry, string etag, TableVersi if (!TryCreateTableVersionRecord(tableVersion.Version, tableVersion.VersionEtag, out var versionEntry)) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - "Update failed. Invalid ETag value. Will retry. Entry {Entry}, eTag {ETag}", - entry.ToString(), - tableVersion.VersionEtag); + LogWarningUpdateFailedInvalidETag(entry, tableVersion.VersionEtag); return false; } @@ -388,12 +354,7 @@ public async Task UpdateRow(MembershipEntry entry, string etag, TableVersi if (canceledException.Message.Contains("ConditionalCheckFailed")) //not a good way to check for this currently { result = false; - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - canceledException, - "Update failed due to contention on the table. Will retry. Entry {Entry}, eTag {ETag}", - entry.ToString(), - etag); + LogWarningUpdateFailedDueToContention(canceledException, entry, etag); } else { @@ -405,12 +366,7 @@ public async Task UpdateRow(MembershipEntry entry, string etag, TableVersi } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - exc, - "Intermediate error updating entry {Entry} to the table {TableName}.", - entry.ToString(), - this.options.TableName); + LogWarningIntermediateErrorUpdatingEntry(exc, entry, this.options.TableName); throw; } } @@ -419,7 +375,7 @@ public async Task UpdateIAmAlive(MembershipEntry entry) { try { - if (this.logger.IsEnabled(LogLevel.Debug)) this.logger.LogDebug("Merge entry = {Entry}", entry.ToString()); + LogDebugMergeEntry(entry); var siloEntry = ConvertPartial(entry); var fields = new Dictionary { { SiloInstanceRecord.I_AM_ALIVE_TIME_PROPERTY_NAME, new AttributeValue(siloEntry.IAmAliveTime) } }; var expression = $"attribute_exists({SiloInstanceRecord.DEPLOYMENT_ID_PROPERTY_NAME}) AND attribute_exists({SiloInstanceRecord.SILO_IDENTITY_PROPERTY_NAME})"; @@ -427,12 +383,7 @@ public async Task UpdateIAmAlive(MembershipEntry entry) } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.MembershipBase, - exc, - "Intermediate error updating IAmAlive field for entry {Entry} to the table {TableName}.", - entry.ToString(), - this.options.TableName); + LogWarningIntermediateErrorUpdatingIAmAlive(exc, entry, this.options.TableName); throw; } } @@ -459,11 +410,7 @@ private MembershipTableData Convert(List entries) } catch (Exception exc) { - this.logger.LogError( - (int)ErrorCode.MembershipBase, - exc, - "Intermediate error parsing SiloInstanceTableEntry to MembershipTableData: {TableEntry}. Ignoring this entry.", - tableEntry); + LogErrorIntermediateErrorParsingSiloInstanceTableEntry(exc, tableEntry); } } } @@ -472,11 +419,7 @@ private MembershipTableData Convert(List entries) } catch (Exception exc) { - this.logger.LogError( - (int)ErrorCode.MembershipBase, - exc, - "Intermediate error parsing SiloInstanceTableEntry to MembershipTableData: {Entries}.", - Utils.EnumerableToString(entries)); + LogErrorIntermediateErrorParsingSiloInstanceTableEntries(exc, entries); throw; } } @@ -611,12 +554,7 @@ public async Task CleanupDefunctSiloEntries(DateTimeOffset beforeDate) } catch (Exception exc) { - this.logger.LogError( - (int)ErrorCode.MembershipBase, - exc, - "Unable to clean up defunct membership records on table {TableName} for ClusterId {ClusterId}", - this.options.TableName, - this.clusterId); + LogErrorUnableToCleanUpDefunctMembershipRecords(exc, this.options.TableName, this.clusterId); throw; } } @@ -627,5 +565,131 @@ private static bool SiloIsDefunct(SiloInstanceRecord silo, DateTimeOffset before && iAmAliveTime < beforeDate && silo.Status != (int)SiloStatus.Active; } + + [LoggerMessage( + Level = LogLevel.Information, + Message = "Initializing AWS DynamoDB Membership Table" + )] + private partial void LogInformationInitializingMembershipTable(); + + [LoggerMessage( + Level = LogLevel.Information, + Message = "Created new table version row." + )] + private partial void LogInformationCreatedNewTableVersionRow(); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Unable to delete membership records on table {TableName} for ClusterId {ClusterId}" + )] + private partial void LogErrorUnableToDeleteMembershipRecords(Exception exception, string tableName, string clusterId); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Read my entry {SiloAddress} Table: {TableData}" + )] + private partial void LogTraceReadMyEntry(SiloAddress siloAddress, MembershipTableData tableData); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error reading silo entry for key {SiloAddress} from the table {TableName}" + )] + private partial void LogWarningIntermediateErrorReadingSiloEntry(Exception exception, SiloAddress siloAddress, string tableName); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Found an inconsistency while reading all silo entries" + )] + private partial void LogWarningFoundInconsistencyReadingAllSiloEntries(); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "ReadAll Table {Table}" + )] + private partial void LogTraceReadAllTable(MembershipTableData table); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error reading all silo entries {TableName}." + )] + private partial void LogWarningIntermediateErrorReadingAllSiloEntries(Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Debug, + Message = "InsertRow entry = {Entry}" + )] + private partial void LogDebugInsertRow(MembershipEntry entry); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Insert failed. Invalid ETag value. Will retry. Entry {Entry}, eTag {ETag}" + )] + private partial void LogWarningInsertFailedInvalidETag(MembershipEntry entry, string etag); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Insert failed due to contention on the table. Will retry. Entry {Entry}" + )] + private partial void LogWarningInsertFailedDueToContention(MembershipEntry entry); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error inserting entry {Entry} to the table {TableName}." + )] + private partial void LogWarningIntermediateErrorInsertingEntry(Exception exception, MembershipEntry entry, string tableName); + + [LoggerMessage( + Level = LogLevel.Debug, + Message = "UpdateRow entry = {Entry}, etag = {Etag}" + )] + private partial void LogDebugUpdateRow(MembershipEntry entry, string etag); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Update failed. Invalid ETag value. Will retry. Entry {Entry}, eTag {ETag}" + )] + private partial void LogWarningUpdateFailedInvalidETag(MembershipEntry entry, string etag); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Update failed due to contention on the table. Will retry. Entry {Entry}, eTag {ETag}" + )] + private partial void LogWarningUpdateFailedDueToContention(Exception exception, MembershipEntry entry, string etag); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error updating entry {Entry} to the table {TableName}." + )] + private partial void LogWarningIntermediateErrorUpdatingEntry(Exception exception, MembershipEntry entry, string tableName); + + [LoggerMessage( + Level = LogLevel.Debug, + Message = "Merge entry = {Entry}" + )] + private partial void LogDebugMergeEntry(MembershipEntry entry); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error updating IAmAlive field for entry {Entry} to the table {TableName}." + )] + private partial void LogWarningIntermediateErrorUpdatingIAmAlive(Exception exception, MembershipEntry entry, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Intermediate error parsing SiloInstanceTableEntry to MembershipTableData: {TableEntry}. Ignoring this entry." + )] + private partial void LogErrorIntermediateErrorParsingSiloInstanceTableEntry(Exception exception, SiloInstanceRecord tableEntry); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Intermediate error parsing SiloInstanceTableEntry to MembershipTableData: {Entries}." + )] + private partial void LogErrorIntermediateErrorParsingSiloInstanceTableEntries(Exception exception, IEnumerable entries); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Unable to clean up defunct membership records on table {TableName} for ClusterId {ClusterId}" + )] + private partial void LogErrorUnableToCleanUpDefunctMembershipRecords(Exception exception, string tableName, string clusterId); } } diff --git a/src/AWS/Orleans.Persistence.DynamoDB/Provider/DynamoDBGrainStorage.cs b/src/AWS/Orleans.Persistence.DynamoDB/Provider/DynamoDBGrainStorage.cs index 090e367a323..3996257ca77 100755 --- a/src/AWS/Orleans.Persistence.DynamoDB/Provider/DynamoDBGrainStorage.cs +++ b/src/AWS/Orleans.Persistence.DynamoDB/Provider/DynamoDBGrainStorage.cs @@ -21,7 +21,7 @@ namespace Orleans.Storage /// Dynamo DB storage Provider. /// Persist Grain State in a DynamoDB table either in Json or Binary format. /// - public class DynamoDBGrainStorage : IGrainStorage, ILifecycleParticipant + public partial class DynamoDBGrainStorage : IGrainStorage, ILifecycleParticipant { private const int MAX_DATA_SIZE = 400 * 1024; private const string GRAIN_REFERENCE_PROPERTY_NAME = "GrainReference"; @@ -68,7 +68,7 @@ public async Task Init(CancellationToken ct) var initMsg = string.Format("Init: Name={0} ServiceId={1} Table={2} DeleteStateOnClear={3}", this.name, this.options.ServiceId, this.options.TableName, this.options.DeleteStateOnClear); - this.logger.LogInformation((int)ErrorCode.StorageProviderBase, $"AWS DynamoDB Grain Storage {this.name} is initializing: {initMsg}"); + LogInformationInitializingDynamoDBGrainStorage(logger, this.name, initMsg); this.storage = new DynamoDBStorage( this.logger, @@ -97,13 +97,12 @@ await storage.InitializeTable(this.options.TableName, secondaryIndexes: null, ttlAttributeName: this.options.TimeToLive.HasValue ? GRAIN_TTL_PROPERTY_NAME : null); stopWatch.Stop(); - this.logger.LogInformation((int)ErrorCode.StorageProviderBase, - $"Initializing provider {this.name} of type {this.GetType().Name} in stage {this.options.InitStage} took {stopWatch.ElapsedMilliseconds} Milliseconds."); + LogInformationProviderInitialized(logger, this.name, this.GetType().Name, this.options.InitStage, stopWatch.ElapsedMilliseconds); } catch (Exception exc) { stopWatch.Stop(); - this.logger.LogError((int)ErrorCode.Provider_ErrorFromInit, $"Initialization failed for provider {this.name} of type {this.GetType().Name} in stage {this.options.InitStage} in {stopWatch.ElapsedMilliseconds} Milliseconds.", exc); + LogErrorProviderInitFailed(logger, this.name, this.GetType().Name, this.options.InitStage, stopWatch.ElapsedMilliseconds, exc); throw; } } @@ -118,14 +117,7 @@ public async Task ReadStateAsync(string grainType, GrainId grainId, IGrainSta if (this.storage == null) throw new ArgumentException("GrainState-Table property not initialized"); string partitionKey = GetKeyString(grainId); - if (this.logger.IsEnabled(LogLevel.Trace)) - this.logger.LogTrace( - (int)ErrorCode.StorageProviderBase, - "Reading: GrainType={GrainType} Pk={PartitionKey} GrainId={GrainId} from Table={TableName}", - grainType, - partitionKey, - grainId, - this.options.TableName); + LogTraceReadingGrainState(logger, grainType, partitionKey, grainId, this.options.TableName); string rowKey = AWSUtils.ValidateDynamoDBRowKey(grainType); @@ -181,14 +173,7 @@ public async Task WriteStateAsync(string grainType, GrainId grainId, IGrainSt } catch (Exception exc) { - this.logger.LogError( - (int)ErrorCode.StorageProviderBase, - exc, - "Error Writing: GrainType={GrainType} GrainId={GrainId} ETag={ETag} to Table={TableName}", - grainType, - grainId, - grainState.ETag, - this.options.TableName); + LogErrorWritingGrainState(logger, exc, grainType, grainId, grainState.ETag, this.options.TableName); throw; } } @@ -266,18 +251,8 @@ public async Task ClearStateAsync(string grainType, GrainId grainId, IGrainSt if (this.storage == null) throw new ArgumentException("GrainState-Table property not initialized"); string partitionKey = GetKeyString(grainId); - if (this.logger.IsEnabled(LogLevel.Trace)) - { - this.logger.LogTrace( - (int)ErrorCode.StorageProviderBase, - "Clearing: GrainType={GrainType} Pk={PartitionKey} GrainId={GrainId} ETag={ETag} DeleteStateOnClear={DeleteStateOnClear} from Table={TableName}", - grainType, - partitionKey, - grainId, - grainState.ETag, - this.options.DeleteStateOnClear, - this.options.TableName); - } + LogTraceClearingGrainState(logger, grainType, partitionKey, grainId, grainState.ETag, this.options.DeleteStateOnClear, this.options.TableName); + string rowKey = AWSUtils.ValidateDynamoDBRowKey(grainType); var record = new GrainStateRecord { GrainReference = partitionKey, ETag = string.IsNullOrWhiteSpace(grainState.ETag) ? 0 : int.Parse(grainState.ETag), GrainType = rowKey }; @@ -303,15 +278,7 @@ public async Task ClearStateAsync(string grainType, GrainId grainId, IGrainSt } catch (Exception exc) { - this.logger.LogError( - (int)ErrorCode.StorageProviderBase, - exc, - "Error {Operation}: GrainType={GrainType} GrainId={GrainId} ETag={ETag} from Table={TableName}", - operation, - grainType, - grainId, - grainState.ETag, - this.options.TableName); + LogErrorClearingGrainState(logger, exc, operation, grainType, grainId, grainState.ETag, this.options.TableName); throw; } } @@ -349,7 +316,7 @@ internal T ConvertFromStorageFormat(GrainStateRecord entity) } var message = sb.ToString(); - this.logger.LogError(exc, "{Message}", message); + LogError(logger, message); throw new AggregateException(message, exc); } @@ -363,8 +330,7 @@ internal void ConvertToStorageFormat(object grainState, GrainStateRecord entity) entity.State = this.options.GrainStorageSerializer.Serialize(grainState).ToArray(); dataSize = BINARY_STATE_PROPERTY_NAME.Length + entity.State.Length; - if (this.logger.IsEnabled(LogLevel.Trace)) this.logger.LogTrace("Writing binary data size = {DataSize} for grain id = Partition={Partition} / Row={Row}", - dataSize, entity.GrainReference, entity.GrainType); + LogTraceWritingBinaryData(logger, dataSize, entity.GrainReference, entity.GrainType); var pkSize = GRAIN_REFERENCE_PROPERTY_NAME.Length + entity.GrainReference.Length; var rkSize = GRAIN_TYPE_PROPERTY_NAME.Length + entity.GrainType.Length; @@ -385,6 +351,61 @@ private void ResetGrainState(IGrainState grainState) } private T CreateInstance() => _activatorProvider.GetActivator().Create(); + + [LoggerMessage( + Level = LogLevel.Information, + Message = "AWS DynamoDB Grain Storage {Name} is initializing: {InitMsg}" + )] + private static partial void LogInformationInitializingDynamoDBGrainStorage(ILogger logger, string name, string initMsg); + + [LoggerMessage( + Level = LogLevel.Information, + Message = "Initializing provider {Name} of type {Type} in stage {Stage} took {ElapsedMilliseconds} Milliseconds." + )] + private static partial void LogInformationProviderInitialized(ILogger logger, string name, string type, int stage, long elapsedMilliseconds); + + [LoggerMessage( + EventId = (int)ErrorCode.Provider_ErrorFromInit, + Level = LogLevel.Error, + Message = "Initialization failed for provider {Name} of type {Type} in stage {Stage} in {ElapsedMilliseconds} Milliseconds." + )] + private static partial void LogErrorProviderInitFailed(ILogger logger, string name, string type, int stage, long elapsedMilliseconds, Exception exception); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Reading: GrainType={GrainType} Pk={PartitionKey} GrainId={GrainId} from Table={TableName}" + )] + private static partial void LogTraceReadingGrainState(ILogger logger, string grainType, string partitionKey, GrainId grainId, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Error Writing: GrainType={GrainType} GrainId={GrainId} ETag={ETag} to Table={TableName}" + )] + private static partial void LogErrorWritingGrainState(ILogger logger, Exception exception, string grainType, GrainId grainId, string eTag, string tableName); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Clearing: GrainType={GrainType} Pk={PartitionKey} GrainId={GrainId} ETag={ETag} DeleteStateOnClear={DeleteStateOnClear} from Table={TableName}" + )] + private static partial void LogTraceClearingGrainState(ILogger logger, string grainType, string partitionKey, GrainId grainId, string eTag, bool deleteStateOnClear, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Error {Operation}: GrainType={GrainType} GrainId={GrainId} ETag={ETag} from Table={TableName}" + )] + private static partial void LogErrorClearingGrainState(ILogger logger, Exception exception, string operation, string grainType, GrainId grainId, string eTag, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "{Message}" + )] + private static partial void LogError(ILogger logger, string message); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Writing binary data size = {DataSize} for grain id = Partition={Partition} / Row={Row}" + )] + private static partial void LogTraceWritingBinaryData(ILogger logger, int dataSize, string partition, string row); } public static class DynamoDBGrainStorageFactory diff --git a/src/AWS/Orleans.Reminders.DynamoDB/Reminders/DynamoDBReminderTable.cs b/src/AWS/Orleans.Reminders.DynamoDB/Reminders/DynamoDBReminderTable.cs index ccfcc1cca88..496644ef93a 100644 --- a/src/AWS/Orleans.Reminders.DynamoDB/Reminders/DynamoDBReminderTable.cs +++ b/src/AWS/Orleans.Reminders.DynamoDB/Reminders/DynamoDBReminderTable.cs @@ -13,7 +13,7 @@ namespace Orleans.Reminders.DynamoDB /// /// Implementation for IReminderTable using DynamoDB as underlying storage. /// - internal sealed class DynamoDBReminderTable : IReminderTable + internal sealed partial class DynamoDBReminderTable : IReminderTable { private const string GRAIN_REFERENCE_PROPERTY_NAME = "GrainReference"; private const string REMINDER_NAME_PROPERTY_NAME = "ReminderName"; @@ -63,7 +63,7 @@ public Task Init() this.options.CreateIfNotExists, this.options.UpdateIfExists); - this.logger.LogInformation((int)ErrorCode.ReminderServiceBase, "Initializing AWS DynamoDB Reminders Table"); + LogInformationInitializingDynamoDBRemindersTable(logger); var serviceIdGrainHashGlobalSecondaryIndex = new GlobalSecondaryIndex { @@ -126,12 +126,7 @@ public async Task ReadRow(GrainId grainId, string reminderName) } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.ReminderServiceBase, - exc, - "Intermediate error reading reminder entry {Utils.DictionaryToString(keys)} from table {this.options.TableName}.", - Utils.DictionaryToString(keys), - this.options.TableName); + LogWarningReadReminderEntry(logger, exc, new(keys), this.options.TableName); throw; } } @@ -158,12 +153,7 @@ public async Task ReadRows(GrainId grainId) } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.ReminderServiceBase, - exc, - "Intermediate error reading reminder entry {Entries} from table {TableName}.", - Utils.DictionaryToString(expressionValues), - this.options.TableName); + LogWarningReadReminderEntries(logger, exc, new(expressionValues), this.options.TableName); throw; } } @@ -218,12 +208,7 @@ public async Task ReadRows(uint begin, uint end) } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.ReminderServiceBase, - exc, - "Intermediate error reading reminder entry {Utils.DictionaryToString(expressionValues)} from table {this.options.TableName}.", - Utils.DictionaryToString(expressionValues), - this.options.TableName); + LogWarningReadReminderEntryRange(logger, exc, new(expressionValues), this.options.TableName); throw; } } @@ -308,12 +293,7 @@ public async Task TestOnlyClearTable() } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.ReminderServiceBase, - exc, - "Intermediate error removing reminder entries {Entries} from table {TableName}.", - Utils.DictionaryToString(expressionValues), - this.options.TableName); + LogWarningRemoveReminderEntries(logger, exc, new(expressionValues), this.options.TableName); throw; } } @@ -341,7 +321,7 @@ public async Task UpsertRow(ReminderEntry entry) try { - if (this.logger.IsEnabled(LogLevel.Debug)) this.logger.LogDebug("UpsertRow entry = {Entry}, etag = {ETag}", entry.ToString(), entry.ETag); + LogDebugUpsertRow(logger, entry, entry.ETag); await this.storage.PutEntryAsync(this.options.TableName, fields); @@ -350,16 +330,64 @@ public async Task UpsertRow(ReminderEntry entry) } catch (Exception exc) { - this.logger.LogWarning( - (int)ErrorCode.ReminderServiceBase, - exc, - "Intermediate error updating entry {Entry} to the table {TableName}.", - entry.ToString(), - options.TableName); + LogWarningUpdateReminderEntry(logger, exc, entry, options.TableName); throw; } } private static string ConstructReminderId(string serviceId, GrainId grainId, string reminderName) => $"{serviceId}_{grainId}_{reminderName}"; + + [LoggerMessage( + EventId = (int)ErrorCode.ReminderServiceBase, + Level = LogLevel.Information, + Message = "Initializing AWS DynamoDB Reminders Table" + )] + private static partial void LogInformationInitializingDynamoDBRemindersTable(ILogger logger); + + private readonly struct DictionaryLogRecord(Dictionary keys) + { + public override string ToString() => Utils.DictionaryToString(keys); + } + + [LoggerMessage( + EventId = (int)ErrorCode.ReminderServiceBase, + Level = LogLevel.Warning, + Message = "Intermediate error reading reminder entry {Keys} from table {TableName}." + )] + private static partial void LogWarningReadReminderEntry(ILogger logger, Exception exception, DictionaryLogRecord keys, string tableName); + + [LoggerMessage( + EventId = (int)ErrorCode.ReminderServiceBase, + Level = LogLevel.Warning, + Message = "Intermediate error reading reminder entry {Entries} from table {TableName}." + )] + private static partial void LogWarningReadReminderEntries(ILogger logger, Exception exception, DictionaryLogRecord entries, string tableName); + + [LoggerMessage( + EventId = (int)ErrorCode.ReminderServiceBase, + Level = LogLevel.Warning, + Message = "Intermediate error reading reminder entry {ExpressionValues} from table {TableName}." + )] + private static partial void LogWarningReadReminderEntryRange(ILogger logger, Exception exception, DictionaryLogRecord expressionValues, string tableName); + + [LoggerMessage( + EventId = (int)ErrorCode.ReminderServiceBase, + Level = LogLevel.Warning, + Message = "Intermediate error removing reminder entries {Entries} from table {TableName}." + )] + private static partial void LogWarningRemoveReminderEntries(ILogger logger, Exception exception, DictionaryLogRecord entries, string tableName); + + [LoggerMessage( + Level = LogLevel.Debug, + Message = "UpsertRow entry = {Entry}, etag = {ETag}" + )] + private static partial void LogDebugUpsertRow(ILogger logger, ReminderEntry entry, string eTag); + + [LoggerMessage( + EventId = (int)ErrorCode.ReminderServiceBase, + Level = LogLevel.Warning, + Message = "Intermediate error updating entry {Entry} to the table {TableName}." + )] + private static partial void LogWarningUpdateReminderEntry(ILogger logger, Exception exception, ReminderEntry entry, string tableName); } } diff --git a/src/AWS/Orleans.Streaming.SQS/Streams/SQSAdapterReceiver.cs b/src/AWS/Orleans.Streaming.SQS/Streams/SQSAdapterReceiver.cs index 649ea1e0646..7b6e12413fc 100644 --- a/src/AWS/Orleans.Streaming.SQS/Streams/SQSAdapterReceiver.cs +++ b/src/AWS/Orleans.Streaming.SQS/Streams/SQSAdapterReceiver.cs @@ -12,9 +12,9 @@ namespace OrleansAWSUtils.Streams { /// - /// Receives batches of messages from a single partition of a message queue. + /// Receives batches of messages from a single partition of a message queue. /// - internal class SQSAdapterReceiver : IQueueAdapterReceiver + internal partial class SQSAdapterReceiver : IQueueAdapterReceiver { private SQSStorage queue; private long lastReadMessage; @@ -74,7 +74,7 @@ public async Task> GetQueueMessagesAsync(int maxCount) { try { - var queueRef = queue; // store direct ref, in case we are somehow asked to shutdown while we are receiving. + var queueRef = queue; // store direct ref, in case we are somehow asked to shutdown while we are receiving. if (queueRef == null) return new List(); int count = maxCount < 0 || maxCount == QueueAdapterConstants.UNLIMITED_GET_QUEUE_MSG ? @@ -99,7 +99,7 @@ public async Task MessagesDeliveredAsync(IList messages) { try { - var queueRef = queue; // store direct ref, in case we are somehow asked to shutdown while we are receiving. + var queueRef = queue; // store direct ref, in case we are somehow asked to shutdown while we are receiving. if (messages.Count == 0 || queueRef == null) return; List cloudQueueMessages = messages.Cast().Select(b => b.Message).ToList(); outstandingTask = Task.WhenAll(cloudQueueMessages.Select(queueRef.DeleteMessage)); @@ -109,7 +109,7 @@ public async Task MessagesDeliveredAsync(IList messages) } catch (Exception exc) { - logger.LogWarning(exc, "Exception upon DeleteMessage on queue {Id}. Ignoring.", Id); + LogWarningDeleteMessageException(logger, exc, Id); } } finally @@ -117,5 +117,11 @@ public async Task MessagesDeliveredAsync(IList messages) outstandingTask = null; } } + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Exception upon DeleteMessage on queue {Id}. Ignoring." + )] + private static partial void LogWarningDeleteMessageException(ILogger logger, Exception exception, QueueId id); } } diff --git a/src/AWS/Shared/Storage/DynamoDBStorage.cs b/src/AWS/Shared/Storage/DynamoDBStorage.cs index 445077edd4b..884c8a4141f 100755 --- a/src/AWS/Shared/Storage/DynamoDBStorage.cs +++ b/src/AWS/Shared/Storage/DynamoDBStorage.cs @@ -28,7 +28,7 @@ namespace Orleans.Transactions.DynamoDB /// /// Wrapper around AWS DynamoDB SDK. /// - internal class DynamoDBStorage + internal partial class DynamoDBStorage { private readonly string _accessKey; private readonly string _token; @@ -105,10 +105,7 @@ public async Task InitializeTable(string tableName, List keys, { if (!this._createIfNotExists && !this._updateIfExists) { - _logger.LogInformation( - (int)ErrorCode.StorageProviderBase, - "The config values for 'createIfNotExists' and 'updateIfExists' are false. The table '{TableName}' will not be created or updated.", - tableName); + LogInformationTableNotCreatedOrUpdated(_logger, tableName); return; } @@ -121,7 +118,7 @@ public async Task InitializeTable(string tableName, List keys, } catch (Exception exc) { - _logger.LogError((int)ErrorCode.StorageProviderBase, exc, "Could not initialize connection to storage table {TableName}", tableName); + LogErrorCouldNotInitializeTable(_logger, exc, tableName); throw; } } @@ -192,10 +189,7 @@ private async ValueTask CreateTableAsync(string tableName, List TableUpdateTtlAsync(TableDescription t // https://docs.aws.amazon.com/amazondynamodb/latest/APIReference/API_UpdateTimeToLive.html if (describeTimeToLive.TimeToLiveStatus != TimeToLiveStatus.DISABLED) { - _logger.LogError((int)ErrorCode.StorageProviderBase, "TTL is not DISABLED. Cannot update table TTL for table {TableName}. Please update manually.", tableDescription.TableName); + LogErrorTtlNotDisabled(_logger, tableDescription.TableName); return tableDescription; } @@ -384,12 +378,7 @@ await _ddbClient.UpdateTimeToLiveAsync(new UpdateTimeToLiveRequest // We need to swallow this exception as there is no API exposed to determine if the below issue will occur before calling UpdateTimeToLive(Async) // "Time to live has been modified multiple times within a fixed interval". // We can arrive at this situation if the TTL feature was recently disabled on the target table. - _logger.LogError( - (int)ErrorCode.StorageProviderBase, - ddbEx, - "Exception occured while updating table {TableName} TTL attribute to {TtlAttributeName}. Please update manually.", - tableDescription.TableName, - ttlAttributeName); + LogErrorUpdateTtlException(_logger, ddbEx, tableDescription.TableName, ttlAttributeName); return tableDescription; } } @@ -453,7 +442,7 @@ public Task DeleTableAsync(string tableName) } catch (Exception exc) { - _logger.LogError((int)ErrorCode.StorageProviderBase, exc, "Could not delete table {TableName}", tableName); + LogErrorCouldNotDeleteTable(_logger, exc, tableName); throw; } } @@ -468,7 +457,7 @@ public Task DeleTableAsync(string tableName) /// public Task PutEntryAsync(string tableName, Dictionary fields, string conditionExpression = "", Dictionary conditionValues = null) { - if (_logger.IsEnabled(LogLevel.Trace)) _logger.LogTrace("Creating {TableName} table entry: {TableEntry}", tableName, Utils.DictionaryToString(fields)); + LogTraceCreatingTableEntry(_logger, tableName, new(fields)); try { @@ -483,7 +472,7 @@ public Task PutEntryAsync(string tableName, Dictionary f } catch (Exception exc) { - _logger.LogError((int)ErrorCode.StorageProviderBase, exc, "Unable to create item to table {TableName}", tableName); + LogErrorUnableToCreateItem(_logger, exc, tableName); throw; } } @@ -504,12 +493,7 @@ public async Task UpsertEntryAsync(string tableName, Dictionary conditionValues = null, string extraExpression = "", Dictionary extraExpressionValues = null) { - if (_logger.IsEnabled(LogLevel.Trace)) - _logger.LogTrace( - "Upserting entry {Entry} with key(s) {Keys} into table {TableName}", - Utils.DictionaryToString(fields), - Utils.DictionaryToString(keys), - tableName); + LogTraceUpsertingEntry(_logger, new(fields), new(keys), tableName); try { @@ -542,11 +526,7 @@ public async Task UpsertEntryAsync(string tableName, Dictionary public Task DeleteEntryAsync(string tableName, Dictionary keys, string conditionExpression = "", Dictionary conditionValues = null) { - if (_logger.IsEnabled(LogLevel.Trace)) _logger.LogTrace("Deleting table {TableName} entry with key(s) {Keys}", tableName, Utils.DictionaryToString(keys)); + LogTraceDeletingTableEntry(_logger, tableName, new(keys)); try { @@ -624,11 +604,7 @@ public Task DeleteEntryAsync(string tableName, Dictionary public Task DeleteEntriesAsync(string tableName, IReadOnlyCollection> toDelete) { - if (_logger.IsEnabled(LogLevel.Trace)) _logger.LogTrace("Deleting {TableName} table entries", tableName); + LogTraceDeletingTableEntries(_logger, tableName); if (toDelete == null) throw new ArgumentNullException(nameof(toDelete)); @@ -666,11 +642,7 @@ public Task DeleteEntriesAsync(string tableName, IReadOnlyCollection ReadSingleEntryAsync(string tableName, Dicti } catch (Exception) { - if (_logger.IsEnabled(LogLevel.Debug)) _logger.LogDebug("Unable to find table entry for Keys = {Keys}", Utils.DictionaryToString(keys)); + LogDebugUnableToFindTableEntry(_logger, new(keys)); throw; } } @@ -756,7 +728,7 @@ public async Task ReadSingleEntryAsync(string tableName, Dicti } catch (Exception) { - if (_logger.IsEnabled(LogLevel.Debug)) _logger.LogDebug("Unable to find table entry for Keys = {Keys}", Utils.DictionaryToString(keys)); + LogDebugUnableToFindTableEntry(_logger, new(keys)); throw; } } @@ -853,7 +825,7 @@ public async Task> ScanAsync(string tableName, Dictionary } catch (Exception exc) { - _logger.LogWarning((int)ErrorCode.StorageProviderBase, exc, "Failed to read table {TableName}", tableName); + LogWarningFailedToReadTable(_logger, exc, tableName); throw new OrleansException($"Failed to read table {tableName}: {exc.Message}", exc); } } @@ -866,7 +838,7 @@ public async Task> ScanAsync(string tableName, Dictionary /// public Task PutEntriesAsync(string tableName, IReadOnlyCollection> toCreate) { - if (_logger.IsEnabled(LogLevel.Trace)) _logger.LogTrace("Put entries {TableName} table", tableName); + LogTracePutEntries(_logger, tableName); if (toCreate == null) throw new ArgumentNullException(nameof(toCreate)); @@ -891,11 +863,7 @@ public Task PutEntriesAsync(string tableName, IReadOnlyCollection> GetEntriesTxAsync(string tableN } catch (Exception) { - if (_logger.IsEnabled(LogLevel.Debug)) - _logger.LogDebug( - "Unable to find table entry for Keys = {Keys}", - Utils.EnumerableToString(keys, d => Utils.DictionaryToString(d))); + LogDebugUnableToFindTableEntries(_logger, new(keys)); throw; } } @@ -977,10 +942,157 @@ public Task WriteTxAsync(IEnumerable puts = null, IEnumerable updat } catch (Exception exc) { - if (_logger.IsEnabled(LogLevel.Debug)) _logger.LogDebug(exc, "Unable to write"); + LogDebugUnableToWrite(_logger, exc); throw; } } - } + private readonly struct DictionaryLogRecord(Dictionary dictionary) + { + public override string ToString() => Utils.DictionaryToString(dictionary); + } + + [LoggerMessage( + Level = LogLevel.Information, + Message = "The config values for 'createIfNotExists' and 'updateIfExists' are false. The table '{TableName}' will not be created or updated." + )] + private static partial void LogInformationTableNotCreatedOrUpdated(ILogger logger, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Could not initialize connection to storage table {TableName}" + )] + private static partial void LogErrorCouldNotInitializeTable(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "The config value 'createIfNotExists' is false. The table '{TableName}' does not exist and it will not get created." + )] + private static partial void LogWarningTableNotCreated(ILogger logger, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Could not create table {TableName}" + )] + private static partial void LogErrorCouldNotCreateTable(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "The config value 'updateIfExists' is false. The table structure for table '{TableName}' will not be updated." + )] + private static partial void LogWarningTableNotUpdated(ILogger logger, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Could not update table {TableName}" + )] + private static partial void LogErrorCouldNotUpdateTable(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "TTL is not DISABLED. Cannot update table TTL for table {TableName}. Please update manually." + )] + private static partial void LogErrorTtlNotDisabled(ILogger logger, string tableName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Exception occured while updating table {TableName} TTL attribute to {TtlAttributeName}. Please update manually." + )] + private static partial void LogErrorUpdateTtlException(ILogger logger, Exception exception, string tableName, string ttlAttributeName); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Could not delete table {TableName}" + )] + private static partial void LogErrorCouldNotDeleteTable(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Creating {TableName} table entry: {TableEntry}" + )] + private static partial void LogTraceCreatingTableEntry(ILogger logger, string tableName, DictionaryLogRecord tableEntry); + + [LoggerMessage( + Level = LogLevel.Error, + Message = "Unable to create item to table {TableName}" + )] + private static partial void LogErrorUnableToCreateItem(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Upserting entry {Entry} with key(s) {Keys} into table {TableName}" + )] + private static partial void LogTraceUpsertingEntry(ILogger logger, DictionaryLogRecord entry, DictionaryLogRecord keys, string tableName); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error upserting to the table {TableName}" + )] + private static partial void LogWarningIntermediateUpsert(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Deleting table {TableName} entry with key(s) {Keys}" + )] + private static partial void LogTraceDeletingTableEntry(ILogger logger, string tableName, DictionaryLogRecord keys); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error deleting entry from the table {TableName}." + )] + private static partial void LogWarningIntermediateDelete(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Deleting {TableName} table entries" + )] + private static partial void LogTraceDeletingTableEntries(ILogger logger, string tableName); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error deleting entries from the table {TableName}." + )] + private static partial void LogWarningIntermediateDeleteEntries(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Trace, + Message = "Put entries {TableName} table" + )] + private static partial void LogTracePutEntries(ILogger logger, string tableName); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Intermediate error bulk inserting entries to table {TableName}." + )] + private static partial void LogWarningIntermediateBulkInsert(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Debug, + Message = "Unable to find table entry for Keys = {Keys}" + )] + private static partial void LogDebugUnableToFindTableEntry(ILogger logger, DictionaryLogRecord keys); + + private readonly struct DictionariesLogRecord(IEnumerable> keys) + { + public override string ToString() => Utils.EnumerableToString(keys, d => Utils.DictionaryToString(d)); + } + + [LoggerMessage( + Level = LogLevel.Debug, + Message = "Unable to find table entry for Keys = {Keys}" + )] + private static partial void LogDebugUnableToFindTableEntries(ILogger logger, DictionariesLogRecord keys); + + [LoggerMessage( + Level = LogLevel.Warning, + Message = "Failed to read table {TableName}" + )] + private static partial void LogWarningFailedToReadTable(ILogger logger, Exception exception, string tableName); + + [LoggerMessage( + Level = LogLevel.Debug, + Message = "Unable to write" + )] + private static partial void LogDebugUnableToWrite(ILogger logger, Exception exception); + } }