From fc71a4592961fd69dcab0d9a3ed90160208dcfa8 Mon Sep 17 00:00:00 2001 From: Maxwell Weru Date: Thu, 21 Sep 2023 08:15:27 +0300 Subject: [PATCH] Make use of logging source generators except for temporary logs --- .../ProcessSynchronizationConsumer.cs | 4 +- .../TriggerUpdateJobsEventConsumer.cs | 14 +- .../Consumers/UpdateJobEventsConsumer.cs | 13 +- .../Controllers/WebhooksController.cs | 22 +-- .../Extensions/ILoggerExtensions.cs | 136 ++++++++++++++++++ .../PeriodicTasks/MissedTriggerCheckerTask.cs | 2 +- .../PeriodicTasks/UpdateJobsCleanerTask.cs | 4 +- .../Workflow/Synchronizer.cs | 22 +-- .../Workflow/UpdateRunner.cs | 6 +- .../Workflow/UpdateScheduler.cs | 4 +- 10 files changed, 176 insertions(+), 51 deletions(-) create mode 100644 server/Tingle.Dependabot/Extensions/ILoggerExtensions.cs diff --git a/server/Tingle.Dependabot/Consumers/ProcessSynchronizationConsumer.cs b/server/Tingle.Dependabot/Consumers/ProcessSynchronizationConsumer.cs index 2f397cd8..158f7ede 100644 --- a/server/Tingle.Dependabot/Consumers/ProcessSynchronizationConsumer.cs +++ b/server/Tingle.Dependabot/Consumers/ProcessSynchronizationConsumer.cs @@ -29,7 +29,7 @@ public async Task ConsumeAsync(EventContext context, Can var project = await dbContext.Projects.SingleOrDefaultAsync(r => r.Id == projectId, cancellationToken); if (project is null) { - logger.LogWarning("Skipping trigger for update because project '{Project}' does not exist.", projectId); + logger.SkippingSyncProjectNotFound(projectId); return; } @@ -40,7 +40,7 @@ public async Task ConsumeAsync(EventContext context, Can var repository = await dbContext.Repositories.SingleOrDefaultAsync(r => r.ProjectId == project.Id && r.Id == repositoryId, cancellationToken); if (repository is null) { - logger.LogWarning("Skipping synchronization because repository '{Repository}' does not exist.", repositoryId); + logger.SkippingSyncRepositoryNotFound(repositoryId); return; } diff --git a/server/Tingle.Dependabot/Consumers/TriggerUpdateJobsEventConsumer.cs b/server/Tingle.Dependabot/Consumers/TriggerUpdateJobsEventConsumer.cs index dec830fd..40925dba 100644 --- a/server/Tingle.Dependabot/Consumers/TriggerUpdateJobsEventConsumer.cs +++ b/server/Tingle.Dependabot/Consumers/TriggerUpdateJobsEventConsumer.cs @@ -29,7 +29,7 @@ public async Task ConsumeAsync(EventContext context, Can var project = await dbContext.Projects.SingleOrDefaultAsync(r => r.Id == projectId, cancellationToken); if (project is null) { - logger.LogWarning("Skipping trigger for update because project '{Project}' does not exist.", projectId); + logger.SkippingTriggerProjectNotFound(projectId); return; } @@ -38,7 +38,7 @@ public async Task ConsumeAsync(EventContext context, Can var repository = await dbContext.Repositories.SingleOrDefaultAsync(r => r.Id == repositoryId, cancellationToken); if (repository is null) { - logger.LogWarning("Skipping trigger for update because repository '{Repository}' does not exist.", repositoryId); + logger.SkippingTriggerRepositoryNotFound(repositoryId: repositoryId, projectId: project.Id); return; } @@ -50,7 +50,7 @@ public async Task ConsumeAsync(EventContext context, Can var update = repository.Updates.ElementAtOrDefault(repositoryUpdateId.Value); if (update is null) { - logger.LogWarning("Skipping trigger for update because repository update '{RepositoryUpdateId}' does not exist.", repositoryUpdateId); + logger.SkippingTriggerRepositoryUpdateNotFound(repositoryId: repositoryId, repositoryUpdateId.Value, projectId: project.Id); return; } updates = new[] { update, }; @@ -70,10 +70,10 @@ public async Task ConsumeAsync(EventContext context, Can var job = await dbContext.UpdateJobs.SingleOrDefaultAsync(j => j.PackageEcosystem == ecosystem && j.Directory == update.Directory && j.EventBusId == eventBusId, cancellationToken); if (job is not null) { - logger.LogWarning("A job for update '{RepositoryId}({UpdateId})' requested by event '{EventBusId}' already exists. Skipping it ...", - repository.Id, - repository.Updates.IndexOf(update), - eventBusId); + logger.SkippingTriggerJobAlreadyExists(repositoryId: repository.Id, + repositoryUpdateId: repository.Updates.IndexOf(update), + projectId: project.Id, + eventBusId: eventBusId); } else { diff --git a/server/Tingle.Dependabot/Consumers/UpdateJobEventsConsumer.cs b/server/Tingle.Dependabot/Consumers/UpdateJobEventsConsumer.cs index 7cc0b93c..d6f9e96b 100644 --- a/server/Tingle.Dependabot/Consumers/UpdateJobEventsConsumer.cs +++ b/server/Tingle.Dependabot/Consumers/UpdateJobEventsConsumer.cs @@ -1,4 +1,5 @@ using Microsoft.EntityFrameworkCore; +using Microsoft.Extensions.Logging; using Tingle.Dependabot.Events; using Tingle.Dependabot.Models; using Tingle.Dependabot.Models.Management; @@ -29,14 +30,14 @@ public async Task ConsumeAsync(EventContext context, C var job = await dbContext.UpdateJobs.SingleOrDefaultAsync(j => j.Id == jobId, cancellationToken); if (job is null) { - logger.LogWarning("Cannot update state for job '{UpdateJobId}' as it does not exist.", jobId); + logger.UpdateJobCannotUpdateStateNotFound(jobId); return; } // skip jobs in a terminal state (useful when reprocessed events) if (job.Status is UpdateJobStatus.Succeeded or UpdateJobStatus.Failed) { - logger.LogWarning("Cannot update state for job '{UpdateJobId}' as it is already in a terminal state.", jobId); + logger.UpdateJobCannotUpdateStateTerminalState(job.Id); return; } @@ -44,13 +45,13 @@ public async Task ConsumeAsync(EventContext context, C var state = await updateRunner.GetStateAsync(job, cancellationToken); if (state is null) { - logger.LogInformation("The runner did not provide a state for job '{UpdateJobId}'.", jobId); + logger.UpdateJobRunnerNoState(job.Id); // delete the job if we have been waiting for over 180 minutes and still do not have state var diff = DateTimeOffset.UtcNow - job.Created; if (diff > TimeSpan.FromMinutes(180)) { - logger.LogWarning("Deleting job '{UpdateJobId}' as it has been pending for more than 90 minutes.", jobId); + logger.UpdateJobPendingTooLong(job.Id); // delete the run await updateRunner.DeleteAsync(job, cancellationToken); @@ -108,14 +109,14 @@ public async Task ConsumeAsync(EventContext context, var job = await dbContext.UpdateJobs.SingleOrDefaultAsync(j => j.Id == jobId, cancellationToken); if (job is null) { - logger.LogWarning("Cannot collect logs for job '{UpdateJobId}' as it does not exist.", jobId); + logger.UpdateJobCannotCollectLogsNotFound(jobId); return; } // ensure the job succeeded or failed if (job.Status is not UpdateJobStatus.Succeeded and not UpdateJobStatus.Failed) { - logger.LogWarning("Cannot collect logs for job '{UpdateJobId}' with status '{UpdateJobStatus}'.", job.Id, job.Status); + logger.UpdateJobCannotCollectLogsInvalidStatus(job.Id, job.Status); return; } diff --git a/server/Tingle.Dependabot/Controllers/WebhooksController.cs b/server/Tingle.Dependabot/Controllers/WebhooksController.cs index da4e637f..5ceda174 100644 --- a/server/Tingle.Dependabot/Controllers/WebhooksController.cs +++ b/server/Tingle.Dependabot/Controllers/WebhooksController.cs @@ -29,10 +29,7 @@ public WebhooksController(MainDbContext dbContext, IEventPublisher publisher, IL public async Task PostAsync([FromBody] AzureDevOpsEvent model) { var type = model.EventType; - logger.LogDebug("Received {EventType} notification {NotificationId} on subscription {SubscriptionId}", - type, - model.NotificationId, - model.SubscriptionId); + logger.WebhooksReceivedEvent(type, model.NotificationId, model.SubscriptionId); if (type is AzureDevOpsEventType.GitPush) { @@ -69,20 +66,14 @@ public async Task PostAsync([FromBody] AzureDevOpsEvent model) if (type is AzureDevOpsEventType.GitPullRequestUpdated) { - logger.LogInformation("PR {PullRequestId} in {RepositoryUrl} status updated to {PullRequestStatus}", - prId, - adoRepository.RemoteUrl, - status); + logger.WebhooksPullRequestStatusUpdated(prId, adoRepository.RemoteUrl, status); // TODO: handle the logic for merge conflicts here using events } else if (type is AzureDevOpsEventType.GitPullRequestMerged) { - logger.LogInformation("Merge status {MergeStatus} for PR {PullRequestId} in {RepositoryUrl}", - resource.MergeStatus, - prId, - adoRepository.RemoteUrl); + logger.WebhooksPullRequestMergedStatusUpdated(prId, adoRepository.RemoteUrl, resource.MergeStatus); // TODO: handle the logic for updating other PRs to find merge conflicts (restart merge or attempt merge) @@ -106,17 +97,14 @@ public async Task PostAsync([FromBody] AzureDevOpsEvent model) var content = comment.Content?.Trim(); if (content is not null && content.StartsWith("@dependabot")) { - logger.LogInformation("PR {PullRequestId} in {RepositoryUrl} was commented on: {Content}", - prId, - adoRepository.RemoteUrl, - content); + logger.WebhooksPullRequestCommentedOn(prId, adoRepository.RemoteUrl, content); // TODO: handle the logic for comments here using events } } else { - logger.LogWarning("'{EventType}' events are not supported!", type); + logger.WebhooksReceivedEventUnsupported(type); } return Ok(); diff --git a/server/Tingle.Dependabot/Extensions/ILoggerExtensions.cs b/server/Tingle.Dependabot/Extensions/ILoggerExtensions.cs new file mode 100644 index 00000000..08e4b510 --- /dev/null +++ b/server/Tingle.Dependabot/Extensions/ILoggerExtensions.cs @@ -0,0 +1,136 @@ +using Tingle.Dependabot.Models.Azure; +using Tingle.Dependabot.Models.Management; + +namespace Microsoft.Extensions.Logging; + +internal static partial class ILoggerExtensions +{ + //[LoggerMessage(100, LogLevel.Warning, "Retrying periodic task execution {CurrentTry} of {MaxRetries}")] + //public static partial void RetryingExecutionOfPeriodicTask(this ILogger logger, Exception exception, int currentTry, int maxRetries); + + #region Webhooks (2xx) + + [LoggerMessage(200, LogLevel.Debug, "Received {EventType} notification {NotificationId} on subscription {SubscriptionId}")] + public static partial void WebhooksReceivedEvent(this ILogger logger, AzureDevOpsEventType? eventType, int notificationId, string? subscriptionId); + + [LoggerMessage(201, LogLevel.Information, "PR {PullRequestId} in {RepositoryUrl} status updated to {PullRequestStatus}")] + public static partial void WebhooksPullRequestStatusUpdated(this ILogger logger, int pullRequestId, string? repositoryUrl, string? pullRequestStatus); + + [LoggerMessage(202, LogLevel.Information, "PR {PullRequestId} in {RepositoryUrl} merge status changed to {MergeStatus}")] + public static partial void WebhooksPullRequestMergedStatusUpdated(this ILogger logger, int pullRequestId, string? repositoryUrl, string? mergeStatus); + + [LoggerMessage(203, LogLevel.Information, "PR {PullRequestId} in {RepositoryUrl} was commented on: {CommentContent}")] + public static partial void WebhooksPullRequestCommentedOn(this ILogger logger, int pullRequestId, string? repositoryUrl, string? commentContent); + + [LoggerMessage(204, LogLevel.Warning, "'{EventType}' events are not supported!")] + public static partial void WebhooksReceivedEventUnsupported(this ILogger logger, AzureDevOpsEventType? eventType); + + #endregion + + #region Synchronizer (3xx) + + [LoggerMessage(300, LogLevel.Information, "Skipping synchronization for {ProjectId} since it last happened recently at {Synchronized}.")] + public static partial void SkippingSyncProjectTooSoon(this ILogger logger, string? projectId, DateTimeOffset? synchronized); + + [LoggerMessage(301, LogLevel.Warning, "Skipping sync for update because project '{ProjectId}' does not exist.")] + public static partial void SkippingSyncProjectNotFound(this ILogger logger, string? projectId); + + [LoggerMessage(302, LogLevel.Warning, "Skipping synchronization because repository '{RepositoryId}' does not exist.")] + public static partial void SkippingSyncRepositoryNotFound(this ILogger logger, string? repositoryId); + + [LoggerMessage(303, LogLevel.Debug, "Skipping sync for {RepositoryName} in {ProjectId} because it is disabled or is a fork")] + public static partial void SkippingSyncRepositoryDisabledOrFork(this ILogger logger, string repositoryName, string? projectId); + + [LoggerMessage(304, LogLevel.Debug, "Listing repositories in {ProjectId} ...")] + public static partial void SyncListingRepositories(this ILogger logger, string? projectId); + + [LoggerMessage(305, LogLevel.Debug, "Found {RepositoriesCount} repositories in {ProjectId}")] + public static partial void SyncListingRepositories(this ILogger logger, int repositoriesCount, string? projectId); + + [LoggerMessage(306, LogLevel.Information, "Deleted {RepositoriesCount} repositories that are no longer present in {ProjectId}.")] + public static partial void SyncDeletedRepositories(this ILogger logger, int repositoriesCount, string? projectId); + + [LoggerMessage(307, LogLevel.Information, "Deleting '{RepositorySlug}' in {ProjectId} as it no longer has a configuration file.")] + public static partial void SyncDeletingRepository(this ILogger logger, string? repositorySlug, string? projectId); + + [LoggerMessage(308, LogLevel.Information, "Configuration file for '{RepositorySlug}' in {ProjectId} is new or has been updated.")] + public static partial void SyncConfigFileChanged(this ILogger logger, string? repositorySlug, string? projectId); + + [LoggerMessage(309, LogLevel.Warning, "Skipping '{RepositorySlug}' in {ProjectId}. The YAML file is invalid.")] + public static partial void SyncConfigFileInvalidStructure(this ILogger logger, Exception exception, string? repositorySlug, string? projectId); + + [LoggerMessage(310, LogLevel.Warning, "Skipping '{RepositorySlug}' in {ProjectId}. The parsed configuration is invalid.")] + public static partial void SyncConfigFileInvalidData(this ILogger logger, Exception exception, string? repositorySlug, string? projectId); + + #endregion + + #region Scheduler (4xx) + + [LoggerMessage(400, LogLevel.Debug, "Creating/Updating schedules for repository '{RepositoryId}' in project '{ProjectId}'")] + public static partial void SchedulesUpdating(this ILogger logger, string? repositoryId, string? projectId); + + [LoggerMessage(401, LogLevel.Error, "Timer call back does not have correct argument. Exepected '{ExpectedType}' but got '{ActualType}'")] + public static partial void SchedulesTimerInvalidCallbackArgument(this ILogger logger, string? expectedType, string? actualType); + + [LoggerMessage(402, LogLevel.Warning, "Schedule was missed for {RepositoryId}({UpdateId}) in project '{ProjectId}'. Triggering now ...")] + public static partial void ScheduleTriggerMissed(this ILogger logger, string? repositoryId, int updateId, string? projectId); + + #endregion + + #region Runner (5xx) + + [LoggerMessage(500, LogLevel.Information, "Written job definition file for {UpdateJobId} at {JobDefinitionPath}")] + public static partial void WrittenJobDefinitionFile(this ILogger logger, string? updateJobId, string? jobDefinitionPath); + + [LoggerMessage(501, LogLevel.Information, "Created ContainerApp Job for {UpdateJobId}")] + public static partial void CreatedContainerAppJob(this ILogger logger, string? updateJobId); + + [LoggerMessage(502, LogLevel.Information, "Started ContainerApp Job for {UpdateJobId}")] + public static partial void StartedContainerAppJob(this ILogger logger, string? updateJobId); + + #endregion + + #region Update Jobs (6xx) + + [LoggerMessage(600, LogLevel.Warning, "Cannot update state for job '{UpdateJobId}' as it does not exist.")] + public static partial void UpdateJobCannotUpdateStateNotFound(this ILogger logger, string? updateJobId); + + [LoggerMessage(601, LogLevel.Warning, "Cannot update state for job '{UpdateJobId}' as it is already in a terminal state.")] + public static partial void UpdateJobCannotUpdateStateTerminalState(this ILogger logger, string? updateJobId); + + [LoggerMessage(602, LogLevel.Information, "The runner did not provide a state for job '{UpdateJobId}'.")] + public static partial void UpdateJobRunnerNoState(this ILogger logger, string? updateJobId); + + [LoggerMessage(603, LogLevel.Warning, "Deleting job '{UpdateJobId}' as it has been pending for more than 90 minutes.")] + public static partial void UpdateJobPendingTooLong(this ILogger logger, string? updateJobId); + + [LoggerMessage(604, LogLevel.Warning, "Cannot collect logs for job '{UpdateJobId}' as it does not exist.")] + public static partial void UpdateJobCannotCollectLogsNotFound(this ILogger logger, string? updateJobId); + + [LoggerMessage(605, LogLevel.Warning, "Cannot collect logs for job '{UpdateJobId}' with status '{UpdateJobStatus}'.")] + public static partial void UpdateJobCannotCollectLogsInvalidStatus(this ILogger logger, string? updateJobId, UpdateJobStatus updateJobStatus); + + [LoggerMessage(606, LogLevel.Information, "Found {UpdateJobsCount} jobs that are still pending for more than 10 min. Requesting manual resolution ...")] + public static partial void UpdateJobRequestingManualResolution(this ILogger logger, int updateJobsCount); + + [LoggerMessage(607, LogLevel.Information, "Removed {UpdateJobsCount} jobs that older than {Cutoff}")] + public static partial void UpdateJobRemovedOldJobs(this ILogger logger, int updateJobsCount, DateTimeOffset cutoff); + + #endregion + + #region Update Jobs (7xx) + + [LoggerMessage(700, LogLevel.Warning, "Skipping trigger for update because project '{ProjectId}' does not exist.")] + public static partial void SkippingTriggerProjectNotFound(this ILogger logger, string projectId); + + [LoggerMessage(701, LogLevel.Warning, "Skipping trigger for update because repository '{RepositoryId}' in project '{ProjectId}' does not exist.")] + public static partial void SkippingTriggerRepositoryNotFound(this ILogger logger, string repositoryId, string? projectId); + + [LoggerMessage(702, LogLevel.Warning, "Skipping trigger for update because repository update '{RepositoryId}({RepositoryUpdateId})' in project '{ProjectId}' does not exist.")] + public static partial void SkippingTriggerRepositoryUpdateNotFound(this ILogger logger, string repositoryId, int repositoryUpdateId, string? projectId); + + [LoggerMessage(703, LogLevel.Warning, "A job for update '{RepositoryId}({RepositoryUpdateId})' in project '{ProjectId}' requested by event '{EventBusId}' already exists. Skipping it ...")] + public static partial void SkippingTriggerJobAlreadyExists(this ILogger logger, string? repositoryId, int repositoryUpdateId, string? projectId, string? eventBusId); + + #endregion +} diff --git a/server/Tingle.Dependabot/PeriodicTasks/MissedTriggerCheckerTask.cs b/server/Tingle.Dependabot/PeriodicTasks/MissedTriggerCheckerTask.cs index 8d5f5dcf..204cb93c 100644 --- a/server/Tingle.Dependabot/PeriodicTasks/MissedTriggerCheckerTask.cs +++ b/server/Tingle.Dependabot/PeriodicTasks/MissedTriggerCheckerTask.cs @@ -63,7 +63,7 @@ internal virtual async Task CheckAsync(DateTimeOffset referencePoint, Cancellati // if we missed an execution, trigger one if (missed) { - logger.LogWarning("Schedule was missed for {RepositoryId}({UpdateId}). Triggering now", repository.Id, repository.Updates.IndexOf(update)); + logger.ScheduleTriggerMissed(repositoryId: repository.Id, updateId: repository.Updates.IndexOf(update), projectId: project.Id); // publish event for the job to be run var evt = new TriggerUpdateJobsEvent diff --git a/server/Tingle.Dependabot/PeriodicTasks/UpdateJobsCleanerTask.cs b/server/Tingle.Dependabot/PeriodicTasks/UpdateJobsCleanerTask.cs index af0896da..1199ad69 100644 --- a/server/Tingle.Dependabot/PeriodicTasks/UpdateJobsCleanerTask.cs +++ b/server/Tingle.Dependabot/PeriodicTasks/UpdateJobsCleanerTask.cs @@ -39,7 +39,7 @@ orderby j.Created ascending if (jobs.Count > 0) { - logger.LogInformation("Found {Count} jobs that are still pending for more than 10 min. Requesting manual resolution ...", jobs.Count); + logger.UpdateJobRequestingManualResolution(jobs.Count); var events = jobs.Select(j => new UpdateJobCheckStateEvent { JobId = j.Id, }).ToList(); await publisher.PublishAsync(events, cancellationToken: cancellationToken); @@ -55,7 +55,7 @@ orderby j.Created ascending { dbContext.UpdateJobs.RemoveRange(jobs); await dbContext.SaveChangesAsync(cancellationToken); - logger.LogInformation("Removed {Count} jobs that older than {Cutoff}", jobs.Count, cutoff); + logger.UpdateJobRemovedOldJobs(jobs.Count, cutoff); } } } diff --git a/server/Tingle.Dependabot/Workflow/Synchronizer.cs b/server/Tingle.Dependabot/Workflow/Synchronizer.cs index eeac35af..d35214e3 100644 --- a/server/Tingle.Dependabot/Workflow/Synchronizer.cs +++ b/server/Tingle.Dependabot/Workflow/Synchronizer.cs @@ -36,7 +36,7 @@ public async Task SynchronizeAsync(Project project, bool trigger, CancellationTo // skip if the project last synchronization is less than 1 hour ago if ((DateTimeOffset.UtcNow - project.Synchronized) <= TimeSpan.FromHours(1)) { - logger.LogInformation("Skipping synchronization for {ProjectUrl} since it last happened recently at {Synchronized}.", project.Url, project.Synchronized); + logger.SkippingSyncProjectTooSoon(project.Id, project.Synchronized); return; } @@ -54,9 +54,9 @@ public async Task SynchronizeAsync(Project project, bool trigger, CancellationTo var syncPairs = new List<(SynchronizerConfigurationItem, Repository?)>(); // get the repositories from Azure - logger.LogDebug("Listing repositories ..."); + logger.SyncListingRepositories(project.Id); var adoRepos = await adoProvider.GetRepositoriesAsync(project, cancellationToken); - logger.LogDebug("Found {RepositoriesCount} repositories", adoRepos.Count); + logger.SyncListingRepositories(adoRepos.Count, project.Id); var adoReposMap = adoRepos.ToDictionary(r => r.Id.ToString(), r => r); // synchronize each project @@ -65,7 +65,7 @@ public async Task SynchronizeAsync(Project project, bool trigger, CancellationTo // skip disabled or fork repositories if (adoRepo.IsDisabled is true || adoRepo.IsFork) { - logger.LogInformation("Skipping sync for {RepositoryName} because it is disabled or is a fork", adoRepo.Name); + logger.SkippingSyncRepositoryDisabledOrFork(adoRepo.Name, project.Id); continue; } @@ -90,7 +90,7 @@ public async Task SynchronizeAsync(Project project, bool trigger, CancellationTo var deleted = await dbContext.Repositories.Where(r => !providerIdsToKeep.Contains(r.ProviderId!)).ExecuteDeleteAsync(cancellationToken); if (deleted > 0) { - logger.LogInformation("Deleted {Count} repositories that are no longer present in the project.", deleted); + logger.SyncDeletedRepositories(deleted, project.Id); } // synchronize each repository @@ -113,7 +113,7 @@ public async Task SynchronizeAsync(Project project, Repository repository, bool // skip disabled or fork repository if (adoRepo.IsDisabled is true || adoRepo.IsFork) { - logger.LogInformation("Skipping sync for {RepositoryName} because it is disabled or is a fork", adoRepo.Name); + logger.SkippingSyncRepositoryDisabledOrFork(adoRepo.Name, project.Id); return; } @@ -137,7 +137,7 @@ public async Task SynchronizeAsync(Project project, string? repositoryProviderId // skip disabled or fork repository if (adoRepo.IsDisabled is true || adoRepo.IsFork) { - logger.LogInformation("Skipping sync for {RepositoryName} because it is disabled or is a fork", adoRepo.Name); + logger.SkippingSyncRepositoryDisabledOrFork(adoRepo.Name, project.Id); return; } @@ -167,7 +167,7 @@ internal async Task SynchronizeAsync(Project project, // delete repository if (repository is not null) { - logger.LogInformation("Deleting '{RepositorySlug}' as it no longer has a configuration file.", repository.Slug); + logger.SyncDeletingRepository(repositorySlug: repository.Slug, projectId: project.Id); dbContext.Repositories.Remove(repository); await dbContext.SaveChangesAsync(cancellationToken); @@ -207,7 +207,7 @@ internal async Task SynchronizeAsync(Project project, if (commitChanged) { - logger.LogDebug("Configuration file for '{RepositorySlug}' is new or has been updated.", repository.Slug); + logger.SyncConfigFileChanged(repositorySlug: repository.Slug, projectId: project.Id); // set/update existing values repository.Updated = DateTimeOffset.UtcNow; @@ -237,12 +237,12 @@ internal async Task SynchronizeAsync(Project project, } catch (YamlDotNet.Core.YamlException ye) { - logger.LogWarning(ye, "Skipping '{RepositorySlug}'. The YAML file is invalid.", repository.Slug); + logger.SyncConfigFileInvalidStructure(ye, repositorySlug: repository.Slug, projectId: project.Id); repository.SyncException = ye.Message; } catch (ValidationException ve) { - logger.LogWarning(ve, "Configuration file for '{RepositorySlug}' is invalid.", repository.Slug); + logger.SyncConfigFileInvalidData(ve, repositorySlug: repository.Slug, projectId: project.Id); repository.SyncException = ve.Message; } diff --git a/server/Tingle.Dependabot/Workflow/UpdateRunner.cs b/server/Tingle.Dependabot/Workflow/UpdateRunner.cs index 07713f7e..12cf6233 100644 --- a/server/Tingle.Dependabot/Workflow/UpdateRunner.cs +++ b/server/Tingle.Dependabot/Workflow/UpdateRunner.cs @@ -122,15 +122,15 @@ public async Task CreateAsync(Project project, Repository repository, Repository // write job definition file var jobDefinitionPath = await WriteJobDefinitionAsync(project, update, job, directory, credentials, cancellationToken); - logger.LogInformation("Written job definition file at {JobDefinitionPath}", jobDefinitionPath); + logger.WrittenJobDefinitionFile(job.Id, jobDefinitionPath); // create the ContainerApp Job var operation = await containerAppJobs.CreateOrUpdateAsync(Azure.WaitUntil.Completed, resourceName, data, cancellationToken); - logger.LogInformation("Created ContainerApp Job for {UpdateJobId}", job.Id); + logger.CreatedContainerAppJob(job.Id); // start the ContainerApp Job _ = await operation.Value.StartAsync(Azure.WaitUntil.Completed, cancellationToken: cancellationToken); - logger.LogInformation("Started ContainerApp Job for {UpdateJobId}", job.Id); + logger.StartedContainerAppJob(job.Id); job.Status = UpdateJobStatus.Running; } diff --git a/server/Tingle.Dependabot/Workflow/UpdateScheduler.cs b/server/Tingle.Dependabot/Workflow/UpdateScheduler.cs index eff79df5..2788b4aa 100644 --- a/server/Tingle.Dependabot/Workflow/UpdateScheduler.cs +++ b/server/Tingle.Dependabot/Workflow/UpdateScheduler.cs @@ -30,7 +30,7 @@ public UpdateScheduler(IEventPublisher publisher, IHostApplicationLifetime lifet public async Task CreateOrUpdateAsync(Repository repository, CancellationToken cancellationToken = default) { - logger.LogDebug("Creating/Updating schedules for repository '{RepositoryId}'.", repository.Id); + logger.SchedulesUpdating(repositoryId: repository.Id, projectId: repository.ProjectId); var updates = new List(); foreach (var update in repository.Updates) { @@ -73,7 +73,7 @@ private async Task CustomTimerCallback(CronScheduleTimer timer, object? arg2, Ca { if (arg2 is not TimerPayload payload) { - logger.LogError("Timer call back does not have correct argument"); + logger.SchedulesTimerInvalidCallbackArgument(typeof(TimerPayload).FullName, arg2?.GetType().FullName); return; }