diff --git a/GitHubExtension.sln b/GitHubExtension.sln index 8e7e8aa..77241d7 100644 --- a/GitHubExtension.sln +++ b/GitHubExtension.sln @@ -40,8 +40,6 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "scripts", "scripts", "{A371 EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "GitHubExtension.Test", "test\GitHubExtension\GitHubExtension.Test.csproj", "{D8EFDB34-7019-4807-AE97-1B50891F345D}" EndProject -Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "DevHome.Logging", "src\Logging\DevHome.Logging.csproj", "{FEEEDA62-F746-4160-A3A8-1EE74137F8AB}" -EndProject Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "scripts", "scripts", "{E4D6AB24-08F6-4352-9BB8-8E92148DA618}" ProjectSection(SolutionItems) = preProject test\scripts\CleanDevHome.ps1 = test\scripts\CleanDevHome.ps1 @@ -195,26 +193,6 @@ Global {D8EFDB34-7019-4807-AE97-1B50891F345D}.Release|x64.Build.0 = Release|x64 {D8EFDB34-7019-4807-AE97-1B50891F345D}.Release|x86.ActiveCfg = Release|x86 {D8EFDB34-7019-4807-AE97-1B50891F345D}.Release|x86.Build.0 = Release|x86 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|Any CPU.ActiveCfg = Debug|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|Any CPU.Build.0 = Debug|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|ARM.ActiveCfg = Debug|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|ARM.Build.0 = Debug|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|arm64.ActiveCfg = Debug|arm64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|arm64.Build.0 = Debug|arm64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|x64.ActiveCfg = Debug|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|x64.Build.0 = Debug|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|x86.ActiveCfg = Debug|x86 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Debug|x86.Build.0 = Debug|x86 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|Any CPU.ActiveCfg = Release|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|Any CPU.Build.0 = Release|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|ARM.ActiveCfg = Release|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|ARM.Build.0 = Release|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|arm64.ActiveCfg = Release|arm64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|arm64.Build.0 = Release|arm64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|x64.ActiveCfg = Release|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|x64.Build.0 = Release|x64 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|x86.ActiveCfg = Release|x86 - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB}.Release|x86.Build.0 = Release|x86 EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE @@ -227,7 +205,6 @@ Global {8E1764CB-2FFC-4F23-9FC0-BDE84E519319} = {5BDF2709-4299-49C3-B971-B10747F2925D} {A371A158-E88C-48D1-9397-22844DDC2EF4} = {10E87373-ADA7-408F-9879-0F6BF101BE87} {D8EFDB34-7019-4807-AE97-1B50891F345D} = {429CEDBA-88C4-4315-9EA1-50AB6DF8855C} - {FEEEDA62-F746-4160-A3A8-1EE74137F8AB} = {5BDF2709-4299-49C3-B971-B10747F2925D} {E4D6AB24-08F6-4352-9BB8-8E92148DA618} = {429CEDBA-88C4-4315-9EA1-50AB6DF8855C} EndGlobalSection GlobalSection(ExtensibilityGlobals) = postSolution diff --git a/build/azure-pipelines.yml b/build/azure-pipelines.yml index 3af0ea2..d5c8b0a 100644 --- a/build/azure-pipelines.yml +++ b/build/azure-pipelines.yml @@ -20,7 +20,7 @@ parameters: - release variables: - MSIXVersion: '0.1200' + MSIXVersion: '0.1300' solution: '**/GitHubExtension.sln' appxPackageDir: 'AppxPackages' testOutputArtifactDir: 'TestResults' diff --git a/build/scripts/CreateBuildInfo.ps1 b/build/scripts/CreateBuildInfo.ps1 index 53b8a5e..7481b1f 100644 --- a/build/scripts/CreateBuildInfo.ps1 +++ b/build/scripts/CreateBuildInfo.ps1 @@ -5,7 +5,7 @@ Param( ) $Major = "0" -$Minor = "12" +$Minor = "13" $Patch = "99" # default to 99 for local builds $versionSplit = $Version.Split("."); diff --git a/src/GitHubExtension/Client/GithubClientProvider.cs b/src/GitHubExtension/Client/GithubClientProvider.cs index bc53d0b..3d05ee9 100644 --- a/src/GitHubExtension/Client/GithubClientProvider.cs +++ b/src/GitHubExtension/Client/GithubClientProvider.cs @@ -1,15 +1,19 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT License. -using DevHome.Logging.Helpers; using GitHubExtension.DeveloperId; using Microsoft.Windows.DevHome.SDK; using Octokit; +using Serilog; namespace GitHubExtension.Client; public class GitHubClientProvider { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", nameof(GitHubClientProvider))); + + private static readonly ILogger Log = _log.Value; + private readonly GitHubClient publicRepoClient; private static readonly object InstanceLock = new(); @@ -66,18 +70,18 @@ public async Task GetClientForLoggedInDeveloper(bool logRateLimit GitHubClient client; if (devIds == null || !devIds.Any()) { - Log.Logger()?.ReportInfo($"No logged in developer, using public GitHub client."); + Log.Information($"No logged in developer, using public GitHub client."); client = Instance.GetClient(); } else { - Log.Logger()?.ReportInfo($"Using authenticated user: {devIds.First().LoginId}"); + Log.Information($"Using authenticated user: {devIds.First().LoginId}"); client = devIds.First().GitHubClient; } if (client == null) { - Log.Logger()?.ReportError($"Failed creating GitHubClient."); + Log.Error($"Failed creating GitHubClient."); return client!; } @@ -86,11 +90,11 @@ public async Task GetClientForLoggedInDeveloper(bool logRateLimit try { var miscRateLimit = await client.RateLimit.GetRateLimits(); - Log.Logger()?.ReportInfo($"Rate Limit: Remaining: {miscRateLimit.Resources.Core.Remaining} Total: {miscRateLimit.Resources.Core.Limit} Resets: {miscRateLimit.Resources.Core.Reset.ToStringInvariant()}"); + Log.Information($"Rate Limit: Remaining: {miscRateLimit.Resources.Core.Remaining} Total: {miscRateLimit.Resources.Core.Limit} Resets: {miscRateLimit.Resources.Core.Reset}"); } catch (Exception ex) { - Log.Logger()?.ReportError($"Rate limiting not enabled for server.", ex); + Log.Error(ex, $"Rate limiting not enabled for server."); } } diff --git a/src/GitHubExtension/Client/Validation.cs b/src/GitHubExtension/Client/Validation.cs index 24f14d5..d731b91 100644 --- a/src/GitHubExtension/Client/Validation.cs +++ b/src/GitHubExtension/Client/Validation.cs @@ -3,12 +3,17 @@ using GitHubExtension.DataModel; using Octokit; +using Serilog; namespace GitHubExtension.Client; // Validation layer to help parsing GitHub URL. public static class Validation { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", nameof(Validation))); + + private static readonly ILogger Log = _log.Value; + private static bool IsValidHttpUri(string uriString, out Uri? uri) { return Uri.TryCreate(uriString, UriKind.Absolute, out uri) && @@ -17,7 +22,7 @@ private static bool IsValidHttpUri(string uriString, out Uri? uri) public static bool IsValidGitHubURL(Uri uri) { - return IsValidGitHubComURL(uri) || IsValidGitHubEnterpriseServerURL(uri); + return IsValidGitHubComURL(uri) || (IsValidGitHubEnterpriseServerURL(uri) && IsReachableGitHubEnterpriseServerURL(uri).Result); } public static bool IsValidGitHubComURL(Uri uri) @@ -25,7 +30,7 @@ public static bool IsValidGitHubComURL(Uri uri) // Valid GitHub URL has three segments. The first is '/'. if (uri.Segments.Length < 3 || (!uri.Host.Equals("github.com", StringComparison.OrdinalIgnoreCase) && !uri.Host.Equals("www.github.com", StringComparison.OrdinalIgnoreCase))) { - Log.Logger()?.ReportDebug($"{uri.OriginalString} is not a valid GitHub uri"); + Log.Debug($"{uri.OriginalString} is not a valid GitHub uri"); return false; } @@ -39,7 +44,7 @@ public static bool IsValidGitHubEnterpriseServerURL(Uri server) // https://docs.github.com/en/enterprise-server@3.10/admin/configuration/configuring-network-settings/configuring-the-hostname-for-your-instance if (server.Segments.Length < 3) { - Log.Logger()?.ReportDebug($"{server.OriginalString} is not a valid GHES repo uri"); + Log.Debug($"{server.OriginalString} is not a valid GHES repo uri"); return false; } @@ -56,7 +61,7 @@ public static bool IsValidGitHubURL(string url) // Above link shows a work around. if (!IsValidHttpUri(url, out parsedUri) || url == null || parsedUri == null) { - Log.Logger()?.ReportDebug($"{url} is not a valid http uri"); + Log.Debug($"{url} is not a valid http uri"); return false; } @@ -227,13 +232,13 @@ public static async Task IsReachableGitHubEnterpriseServerURL(Uri server) var probeResult = await new EnterpriseProbe(new ProductHeaderValue(Constants.DEV_HOME_APPLICATION_NAME)).Probe(server); if (probeResult != EnterpriseProbeResult.Ok) { - Log.Logger()?.ReportError($"EnterpriseServer {server.AbsoluteUri} is not reachable"); + Log.Error($"EnterpriseServer {server.AbsoluteUri} is not reachable"); return false; } } catch (Exception ex) { - Log.Logger()?.ReportError($"EnterpriseServer {server.AbsoluteUri} could not be probed.", ex); + Log.Error(ex, $"EnterpriseServer {server.AbsoluteUri} could not be probed."); return false; } diff --git a/src/GitHubExtension/DataManager/DataUpdater.cs b/src/GitHubExtension/DataManager/DataUpdater.cs index a2b9f5d..35c6a4f 100644 --- a/src/GitHubExtension/DataManager/DataUpdater.cs +++ b/src/GitHubExtension/DataManager/DataUpdater.cs @@ -1,6 +1,8 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT License. +using Serilog; + namespace GitHubExtension.DataManager; public class DataUpdater : IDisposable @@ -8,6 +10,7 @@ public class DataUpdater : IDisposable // This is the default interval the timer will run. It is not the interval that we necessarily do work. private static readonly TimeSpan TimerUpdateInterval = TimeSpan.FromSeconds(5); + private readonly ILogger _logger; private readonly PeriodicTimer _timer; private readonly Func _action; private CancellationTokenSource _cancelSource; @@ -17,6 +20,7 @@ public class DataUpdater : IDisposable public DataUpdater(TimeSpan interval, Func action) { + _logger = Log.Logger.ForContext("SourceContext", nameof(DataUpdater)); _timer = new PeriodicTimer(interval); _cancelSource = new CancellationTokenSource(); _started = false; @@ -64,7 +68,7 @@ protected virtual void Dispose(bool disposing) { if (!disposed) { - DataModel.Log.Logger()?.ReportDebug(ToString(), "Disposing of all Disposable resources."); + _logger.Debug("Disposing of all updater resources."); if (disposing) { diff --git a/src/GitHubExtension/DataManager/GitHubDataManager.cs b/src/GitHubExtension/DataManager/GitHubDataManager.cs index 36141fe..6883728 100644 --- a/src/GitHubExtension/DataManager/GitHubDataManager.cs +++ b/src/GitHubExtension/DataManager/GitHubDataManager.cs @@ -5,12 +5,17 @@ using GitHubExtension.DataManager; using GitHubExtension.DataModel; using GitHubExtension.Helpers; +using Serilog; using Windows.Storage; namespace GitHubExtension; public partial class GitHubDataManager : IGitHubDataManager, IDisposable { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", nameof(GitHubDataManager))); + + private static readonly ILogger Log = _log.Value; + public static event DataManagerUpdateEventHandler? OnUpdate; private static readonly string LastUpdatedKeyName = "LastUpdated"; @@ -28,8 +33,6 @@ public partial class GitHubDataManager : IGitHubDataManager, IDisposable private static readonly TimeSpan LastObservedDeleteSpan = TimeSpan.FromMinutes(6); private static readonly long CheckSuiteIdDependabot = 29110; - private static readonly string Name = nameof(GitHubDataManager); - private DataStore DataStore { get; set; } public DataStoreOptions DataStoreOptions { get; private set; } @@ -44,7 +47,7 @@ public partial class GitHubDataManager : IGitHubDataManager, IDisposable } catch (Exception e) { - Log.Logger()?.ReportError(Name, "Failed creating GitHubDataManager", e); + Log.Error(e, "Failed creating GitHubDataManager"); Environment.FailFast(e.Message, e); return null; } @@ -250,7 +253,7 @@ private async Task UpdateDataStoreAsync(DataStoreOperationParameters parameters, } catch (Exception ex) { - Log.Logger()?.ReportError(Name, $"Failed Updating DataStore for: {parameters}", ex); + Log.Error(ex, $"Failed Updating DataStore for: {parameters}"); tx.Rollback(); // Rethrow so clients can catch/display an error UX. @@ -258,7 +261,7 @@ private async Task UpdateDataStoreAsync(DataStoreOperationParameters parameters, } tx.Commit(); - Log.Logger()?.ReportInfo(Name, $"Updated datastore: {parameters}"); + Log.Information($"Updated datastore: {parameters}"); } // Wrapper for the targeted repository update pattern. @@ -298,22 +301,22 @@ private async Task UpdateDataForRepositoryAsync(DataStoreOperationParameters par { case Octokit.NotFoundException: // A private repository will come back as "not found" by the GitHub API when an unauthorized account cannot even view it. - Log.Logger()?.ReportDebug(Name, $"DeveloperId {devId.LoginId} did not find {parameters.Owner}/{parameters.RepositoryName}"); + Log.Debug($"DeveloperId {devId.LoginId} did not find {parameters.Owner}/{parameters.RepositoryName}"); continue; case Octokit.RateLimitExceededException: - Log.Logger()?.ReportDebug(Name, $"DeveloperId {devId.LoginId} rate limit exceeded."); + Log.Debug($"DeveloperId {devId.LoginId} rate limit exceeded."); throw; case Octokit.ForbiddenException: // This can happen most commonly with SAML-enabled organizations. // The user may have access but the org blocked the application. - Log.Logger()?.ReportDebug(Name, $"DeveloperId {devId.LoginId} was forbidden access to {parameters.Owner}/{parameters.RepositoryName}"); + Log.Debug($"DeveloperId {devId.LoginId} was forbidden access to {parameters.Owner}/{parameters.RepositoryName}"); throw; default: // If it's some other error like abuse detection, abort and do not continue. - Log.Logger()?.ReportDebug(Name, $"Unhandled Octokit API error for {devId.LoginId} and {parameters.Owner} / {parameters.RepositoryName}"); + Log.Debug($"Unhandled Octokit API error for {devId.LoginId} and {parameters.Owner} / {parameters.RepositoryName}"); throw; } } @@ -331,13 +334,13 @@ private async Task UpdateDataForRepositoryAsync(DataStoreOperationParameters par catch (Exception ex) { // This is for catching any other unexpected error as well as any we throw. - Log.Logger()?.ReportError(Name, $"Failed trying update data for repository: {parameters.Owner}/{parameters.RepositoryName}", ex); + Log.Error(ex, $"Failed trying update data for repository: {parameters.Owner}/{parameters.RepositoryName}"); tx.Rollback(); throw; } tx.Commit(); - Log.Logger()?.ReportInfo(Name, $"Updated datastore: {parameters}"); + Log.Information($"Updated datastore: {parameters}"); } // Find all pull requests the developer, and update them. @@ -348,7 +351,7 @@ private async Task UpdatePullRequestsForLoggedInDeveloperIdsAsync(DataStoreOpera if (devIds is null || !devIds.Any()) { // This may not be an error if the user has not yet logged in with a DevId. - Log.Logger()?.ReportInfo(Name, "Called to update all pull requests for a user with no logged in developer."); + Log.Information("Called to update all pull requests for a user with no logged in developer."); return; } @@ -405,7 +408,7 @@ private async Task UpdatePullRequestsForLoggedInDeveloperIdsAsync(DataStoreOpera // the UI to query it to attempt to resolve any issues discovered in the main // app UX, such as via a user prompt that tells them not all of their data // could be accessed. - Log.Logger()?.ReportWarn(Name, $"Forbidden exception while trying to query repository {repoFullName}: {ex.Message}"); + Log.Warning($"Forbidden exception while trying to query repository {repoFullName}: {ex.Message}"); continue; } @@ -445,7 +448,7 @@ private async Task UpdatePullRequestsForLoggedInDeveloperIdsAsync(DataStoreOpera continue; } - Log.Logger()?.ReportDebug($"Suite: {suite.App.Name} - {suite.App.Id} - {suite.App.Owner.Login} Conclusion: {suite.Conclusion} Status: {suite.Status}"); + Log.Verbose($"Suite: {suite.App.Name} - {suite.App.Id} - {suite.App.Owner.Login} Conclusion: {suite.Conclusion} Status: {suite.Status}"); CheckSuite.GetOrCreateByOctokitCheckSuite(DataStore, suite); } } @@ -454,10 +457,10 @@ private async Task UpdatePullRequestsForLoggedInDeveloperIdsAsync(DataStoreOpera // Octokit can sometimes fail unexpectedly or have bugs. Should that occur here, we // will not stop processing all pull requests and instead skip over getting the PR // checks information for this particular pull request. - Log.Logger()?.ReportError($"Error updating Check Status for Pull Request #{octoPull.Number}: {e.Message}"); + Log.Error($"Error updating Check Status for Pull Request #{octoPull.Number}: {e.Message}"); // Put the full stack trace in debug if this occurs to reduce log spam. - Log.Logger()?.ReportDebug($"Error updating Check Status for Pull Request #{octoPull.Number}.", e); + Log.Debug(e, $"Error updating Check Status for Pull Request #{octoPull.Number}."); } var commitCombinedStatus = await devId.GitHubClient.Repository.Status.GetCombined(dsRepository.InternalId, dsPullRequest.HeadSha); @@ -480,14 +483,14 @@ private async Task UpdatePullRequestsForLoggedInDeveloperIdsAsync(DataStoreOpera // Octokit can sometimes fail unexpectedly or have bugs. Should that occur here, we // will not stop processing all pull requests and instead skip over getting the PR // review information for this particular pull request. - Log.Logger()?.ReportError($"Error updating Reviews for Pull Request #{octoPull.Number}: {e.Message}"); + Log.Error($"Error updating Reviews for Pull Request #{octoPull.Number}: {e.Message}"); // Put the full stack trace in debug if this occurs to reduce log spam. - Log.Logger()?.ReportDebug($"Error updating Reviews for Pull Request #{octoPull.Number}.", e); + Log.Debug(e, $"Error updating Reviews for Pull Request #{octoPull.Number}."); } } - Log.Logger()?.ReportDebug(Name, $"Updated developer pull requests for {repoFullName}."); + Log.Debug($"Updated developer pull requests for {repoFullName}."); } // After we update for this developer, remove all pull requests for this developer that @@ -501,7 +504,7 @@ private async Task UpdatePullRequestsForLoggedInDeveloperIdsAsync(DataStoreOpera private async Task UpdateRepositoryAsync(string owner, string repositoryName, Octokit.GitHubClient? client = null) { client ??= await GitHubClientProvider.Instance.GetClientForLoggedInDeveloper(true); - Log.Logger()?.ReportInfo(Name, $"Updating repository: {owner}/{repositoryName}"); + Log.Information($"Updating repository: {owner}/{repositoryName}"); var octokitRepository = await client.Repository.Get(owner, repositoryName); return Repository.GetOrCreateByOctokitRepository(DataStore, octokitRepository); } @@ -513,7 +516,7 @@ private async Task UpdatePullRequestsAsync(Repository repository, Octokit.GitHub options ??= RequestOptions.RequestOptionsDefault(); client ??= await GitHubClientProvider.Instance.GetClientForLoggedInDeveloper(true); var user = await client.User.Current(); - Log.Logger()?.ReportInfo(Name, $"Updating pull requests for: {repository.FullName} and user: {user.Login}"); + Log.Information($"Updating pull requests for: {repository.FullName} and user: {user.Login}"); var octoPulls = await client.PullRequest.GetAllForRepository(repository.InternalId, options.PullRequestRequest, options.ApiOptions); foreach (var pull in octoPulls) { @@ -536,7 +539,7 @@ private async Task UpdatePullRequestsAsync(Repository repository, Octokit.GitHub continue; } - Log.Logger()?.ReportDebug($"Suite: {suite.App.Name} - {suite.App.Id} - {suite.App.Owner.Login} Conclusion: {suite.Conclusion} Status: {suite.Status}"); + Log.Verbose($"Suite: {suite.App.Name} - {suite.App.Id} - {suite.App.Owner.Login} Conclusion: {suite.Conclusion} Status: {suite.Status}"); CheckSuite.GetOrCreateByOctokitCheckSuite(DataStore, suite); } } @@ -545,10 +548,10 @@ private async Task UpdatePullRequestsAsync(Repository repository, Octokit.GitHub // Octokit can sometimes fail unexpectedly or have bugs. Should that occur here, we // will not stop processing all pull requests and instead skip over getting the PR // checks information for this particular pull request. - Log.Logger()?.ReportError($"Error updating Check Status for Pull Request #{pull.Number}: {e.Message}"); + Log.Error($"Error updating Check Status for Pull Request #{pull.Number}: {e.Message}"); // Put the full stack trace in debug if this occurs to reduce log spam. - Log.Logger()?.ReportDebug($"Error updating Check Status for Pull Request #{pull.Number}.", e); + Log.Debug(e, $"Error updating Check Status for Pull Request #{pull.Number}."); } var commitCombinedStatus = await client.Repository.Status.GetCombined(repository.InternalId, dsPullRequest.HeadSha); @@ -578,7 +581,7 @@ private void ProcessReview(PullRequest pullRequest, Octokit.PullRequestReview oc // Ignore comments or pending state. if (string.IsNullOrEmpty(newReview.State) || newReview.State == "Commented") { - Log.Logger()?.ReportDebug(Name, "Notifications", $"Ignoring review for {pullRequest}. State: {newReview.State}"); + Log.Debug($"Ignoring review for {pullRequest}. State: {newReview.State}"); return; } @@ -586,7 +589,7 @@ private void ProcessReview(PullRequest pullRequest, Octokit.PullRequestReview oc if (existingReview == null || (existingReview.State != newReview.State)) { // We assume that the logged in developer created this pull request. - Log.Logger()?.ReportInfo(Name, "Notifications", $"Creating NewReview Notification for {pullRequest}. State: {newReview.State}"); + Log.Information($"Creating NewReview Notification for {pullRequest}. State: {newReview.State}"); Notification.Create(DataStore, newReview, NotificationType.NewReview); } } @@ -601,13 +604,13 @@ private void CreatePullRequestStatus(PullRequest pullRequest) if (ShouldCreateCheckFailureNotification(curStatus, prevStatus)) { - Log.Logger()?.ReportInfo(Name, "Notifications", $"Creating CheckRunFailure Notification for {curStatus}"); + Log.Information($"Creating CheckRunFailure Notification for {curStatus}"); Notification.Create(DataStore, curStatus, NotificationType.CheckRunFailed); } if (ShouldCreateCheckSucceededNotification(curStatus, prevStatus)) { - Log.Logger()?.ReportDebug(Name, "Notifications", $"Creating CheckRunSuccess Notification for {curStatus}"); + Log.Debug($"Creating CheckRunSuccess Notification for {curStatus}"); Notification.Create(DataStore, curStatus, NotificationType.CheckRunSucceeded); } } @@ -684,7 +687,7 @@ private async Task UpdateIssuesAsync(Repository repository, Octokit.GitHubClient { options ??= RequestOptions.RequestOptionsDefault(); client ??= await GitHubClientProvider.Instance.GetClientForLoggedInDeveloper(true); - Log.Logger()?.ReportInfo(Name, $"Updating issues for: {repository.FullName}"); + Log.Information($"Updating issues for: {repository.FullName}"); // Since we are only interested in issues and for a specific repository, we will override // these two properties. All other properties the caller can specify however they see fit. @@ -694,7 +697,7 @@ private async Task UpdateIssuesAsync(Repository repository, Octokit.GitHubClient var issuesResult = await client.Search.SearchIssues(options.SearchIssuesRequest); if (issuesResult == null) { - Log.Logger()?.ReportDebug($"No issues found."); + Log.Debug($"No issues found."); return; } @@ -702,11 +705,11 @@ private async Task UpdateIssuesAsync(Repository repository, Octokit.GitHubClient Search? search = null; if (!string.IsNullOrEmpty(options.SearchIssuesRequest.Term)) { - Log.Logger()?.ReportDebug($"Term = {options.SearchIssuesRequest.Term}"); + Log.Debug($"Term = {options.SearchIssuesRequest.Term}"); search = Search.GetOrCreate(DataStore, options.SearchIssuesRequest.Term, repository.Id); } - Log.Logger()?.ReportDebug(Name, $"Results contain {issuesResult.Items.Count} issues."); + Log.Debug($"Results contain {issuesResult.Items.Count} issues."); foreach (var issue in issuesResult.Items) { var dsIssue = Issue.GetOrCreateByOctokitIssue(DataStore, issue, repository.Id); @@ -738,16 +741,16 @@ private async Task UpdateReleasesAsync(Repository repository, Octokit.GitHubClie options.ApiOptions.PageSize = 10; client ??= await GitHubClientProvider.Instance.GetClientForLoggedInDeveloper(true); - Log.Logger()?.ReportInfo(Name, $"Updating releases for: {repository.FullName}"); + Log.Information($"Updating releases for: {repository.FullName}"); var releasesResult = await client.Repository.Release.GetAll(repository.InternalId, options.ApiOptions); if (releasesResult == null) { - Log.Logger()?.ReportDebug($"No releases found."); + Log.Debug($"No releases found."); return; } - Log.Logger()?.ReportDebug(Name, $"Results contain {releasesResult.Count} releases."); + Log.Debug($"Results contain {releasesResult.Count} releases."); foreach (var release in releasesResult) { if (release.Draft) @@ -788,7 +791,7 @@ private string[] GetOwnerAndRepositoryNameFromFullName(string fullName) var nameSplit = fullName.Split(new[] { '/' }); if (nameSplit.Length != 2 || string.IsNullOrEmpty(nameSplit[0]) || string.IsNullOrEmpty(nameSplit[1])) { - Log.Logger()?.ReportError(Name, $"Invalid repository full name: {fullName}"); + Log.Error($"Invalid repository full name: {fullName}"); throw new ArgumentException($"Invalid repository full name: {fullName}"); } @@ -844,7 +847,7 @@ protected virtual void Dispose(bool disposing) { if (!disposed) { - Log.Logger()?.ReportDebug(Name, "Disposing of all Disposable resources."); + Log.Debug("Disposing of all Disposable resources."); if (disposing) { diff --git a/src/GitHubExtension/DataManager/GitHubDataManagerUpdate.cs b/src/GitHubExtension/DataManager/GitHubDataManagerUpdate.cs index 1082f6f..f493d04 100644 --- a/src/GitHubExtension/DataManager/GitHubDataManagerUpdate.cs +++ b/src/GitHubExtension/DataManager/GitHubDataManagerUpdate.cs @@ -27,7 +27,7 @@ public static async Task Update() } catch (Exception ex) { - Log.Logger()?.ReportError(Name, "Update", "Update failed unexpectedly.", ex); + Log.Error(ex, "Update failed unexpectedly."); } lastUpdateTime = DateTime.Now; @@ -35,7 +35,7 @@ public static async Task Update() private static async Task UpdateDeveloperPullRequests() { - Log.Logger()?.ReportDebug(Name, "Update", $"Executing UpdateDeveloperPullRequests"); + Log.Debug($"Executing UpdateDeveloperPullRequests"); using var dataManager = CreateInstance() ?? throw new DataStoreInaccessibleException("GitHubDataManager is null."); await dataManager.UpdatePullRequestsForLoggedInDeveloperIdsAsync(); @@ -73,7 +73,7 @@ private static void SendUpdateEvent(object? source, DataManagerUpdateKind kind, { info ??= string.Empty; context ??= Array.Empty(); - Log.Logger()?.ReportInfo(Name, $"Sending Update Event: {kind} Info: {info} Context: {string.Join(",", context)}"); + Log.Information($"Sending Update Event: {kind} Info: {info} Context: {string.Join(",", context)}"); OnUpdate.Invoke(source, new DataManagerUpdateEventArgs(kind, info, context)); } } diff --git a/src/GitHubExtension/DataManager/GitHubSearchManger.cs b/src/GitHubExtension/DataManager/GitHubSearchManger.cs index 7e00e99..90d61d2 100644 --- a/src/GitHubExtension/DataManager/GitHubSearchManger.cs +++ b/src/GitHubExtension/DataManager/GitHubSearchManger.cs @@ -3,9 +3,9 @@ using GitHubExtension.Client; using GitHubExtension.DataManager; -using GitHubExtension.DataModel; using Microsoft.Windows.DevHome.SDK; using Octokit; +using Serilog; namespace GitHubExtension; @@ -13,6 +13,10 @@ namespace GitHubExtension; public partial class GitHubSearchManager : IGitHubSearchManager, IDisposable { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", nameof(GitHubSearchManager))); + + private static readonly ILogger Log = _log.Value; + private static readonly string Name = nameof(GitHubSearchManager); public static event SearchManagerResultsAvailableEventHandler? OnResultsAvailable; @@ -29,7 +33,7 @@ public GitHubSearchManager() } catch (Exception e) { - Log.Logger()?.ReportError(Name, "Failed creating GitHubSearchManager", e); + Log.Error(e, "Failed creating GitHubSearchManager"); Environment.FailFast(e.Message, e); return null; } @@ -51,7 +55,7 @@ public async Task SearchForGitHubIssuesOrPRs(Octokit.SearchIssuesRequest request private async Task SearchForGitHubIssuesOrPRs(Octokit.SearchIssuesRequest request, string initiator, SearchCategory category, GitHubClient client, RequestOptions? options = null) { - Log.Logger()?.ReportInfo(Name, $"Searching for issues or pull requests for widget {initiator}"); + Log.Information(Name, $"Searching for issues or pull requests for widget {initiator}"); request.State = Octokit.ItemState.Open; request.Archived = false; request.PerPage = 10; @@ -72,12 +76,12 @@ private async Task SearchForGitHubIssuesOrPRs(Octokit.SearchIssuesRequest reques var octokitResult = await client.Search.SearchIssues(request); if (octokitResult == null) { - Log.Logger()?.ReportDebug($"No issues or PRs found."); + Log.Debug($"No issues or PRs found."); SendResultsAvailable(new List(), initiator); } else { - Log.Logger()?.ReportDebug(Name, $"Results contain {octokitResult.Items.Count} items."); + Log.Debug($"Results contain {octokitResult.Items.Count} items."); SendResultsAvailable(octokitResult.Items, initiator); } } @@ -86,7 +90,7 @@ private void SendResultsAvailable(IEnumerable results, string ini { if (OnResultsAvailable != null) { - Log.Logger()?.ReportInfo(Name, $"Sending search results available Event, of type: {initiator}"); + Log.Information(Name, $"Sending search results available Event, of type: {initiator}"); OnResultsAvailable.Invoke(results, initiator); } } diff --git a/src/GitHubExtension/DataModel/DataObjects/CheckRun.cs b/src/GitHubExtension/DataModel/DataObjects/CheckRun.cs index 0e2911d..fdbb8cd 100644 --- a/src/GitHubExtension/DataModel/DataObjects/CheckRun.cs +++ b/src/GitHubExtension/DataModel/DataObjects/CheckRun.cs @@ -5,12 +5,17 @@ using Dapper.Contrib.Extensions; using GitHubExtension.Helpers; using Octokit; +using Serilog; namespace GitHubExtension.DataModel; [Table("CheckRun")] public class CheckRun { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", $"DataModel/{nameof(CheckRun)}")); + + private static readonly ILogger Log = _log.Value; + [Key] public long Id { get; set; } = DataStore.NoForeignKey; @@ -129,7 +134,7 @@ private static CheckConclusion GetCheckRunConclusion(StringEnum oct catch (Exception) { // This error means a programming error or Octokit added to or changed their enum. - Log.Logger()?.ReportError($"Found Unknown CheckStatus value: {octoCheckStatus.Value}"); + Log.Error($"Found Unknown CheckStatus value: {octoCheckStatus.Value}"); return CheckStatus.Unknown; } @@ -205,7 +210,7 @@ public static IEnumerable GetFailedCheckRunsForPullRequest(DataStore d MaxConclusion = (long)CheckConclusion.ActionRequired, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); return dataStore.Connection!.Query(sql, param, null) ?? Enumerable.Empty(); } @@ -220,7 +225,7 @@ public static CheckStatus GetCheckRunStatusForPullRequest(DataStore datastore, P pullRequest.HeadSha, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); // Query results in NULL if there are no entries, and QueryFirstOrDefault will throw trying // to assign null to an integer. In this instance we catch it and return the None type. @@ -250,7 +255,7 @@ public static CheckConclusion GetCheckRunConclusionForPullRequest(DataStore data StatusId = (long)CheckStatus.Completed, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); // Query results in NULL if there are no entries, and QueryFirstOrDefault will throw trying // to assign null to an integer. In this instance we catch it and return the None type. @@ -270,9 +275,9 @@ public static void DeleteUnreferenced(DataStore dataStore) var sql = @"DELETE FROM CheckRun WHERE HeadSha NOT IN (SELECT HeadSha FROM PullRequest)"; var command = dataStore.Connection!.CreateCommand(); command.CommandText = sql; - Log.Logger()?.ReportDebug(DataStore.GetCommandLogMessage(sql, command)); + Log.Verbose(DataStore.GetCommandLogMessage(sql, command)); var rowsDeleted = command.ExecuteNonQuery(); - Log.Logger()?.ReportDebug(DataStore.GetDeletedLogMessage(rowsDeleted)); + Log.Verbose(DataStore.GetDeletedLogMessage(rowsDeleted)); } public static void DeleteAllForPullRequest(DataStore dataStore, PullRequest pullRequest) @@ -282,8 +287,8 @@ public static void DeleteAllForPullRequest(DataStore dataStore, PullRequest pull var command = dataStore.Connection!.CreateCommand(); command.CommandText = sql; command.Parameters.AddWithValue("$HeadSha", pullRequest.HeadSha); - Log.Logger()?.ReportDebug(DataStore.GetCommandLogMessage(sql, command)); + Log.Verbose(DataStore.GetCommandLogMessage(sql, command)); var rowsDeleted = command.ExecuteNonQuery(); - Log.Logger()?.ReportDebug(DataStore.GetDeletedLogMessage(rowsDeleted)); + Log.Verbose(DataStore.GetDeletedLogMessage(rowsDeleted)); } } diff --git a/src/GitHubExtension/DataModel/DataObjects/CheckSuite.cs b/src/GitHubExtension/DataModel/DataObjects/CheckSuite.cs index ef09e60..e7df7ea 100644 --- a/src/GitHubExtension/DataModel/DataObjects/CheckSuite.cs +++ b/src/GitHubExtension/DataModel/DataObjects/CheckSuite.cs @@ -4,12 +4,17 @@ using Dapper; using Dapper.Contrib.Extensions; using Octokit; +using Serilog; namespace GitHubExtension.DataModel; [Table("CheckSuite")] public class CheckSuite { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", $"DataModel/{nameof(CheckSuite)}")); + + private static readonly ILogger Log = _log.Value; + [Key] public long Id { get; set; } = DataStore.NoForeignKey; @@ -106,7 +111,7 @@ private static CheckConclusion GetCheckConclusion(StringEnum octoCh catch (Exception) { // This error means a programming error or Octokit added to or changed their enum. - Log.Logger()?.ReportError($"Found Unknown CheckStatus value: {octoCheckStatus.Value}"); + Log.Error($"Found Unknown CheckStatus value: {octoCheckStatus.Value}"); return CheckStatus.Unknown; } @@ -179,7 +184,7 @@ public static CheckStatus GetCheckStatusForPullRequest(DataStore datastore, Pull pullRequest.HeadSha, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); // Query results in NULL if there are no entries, and QueryFirstOrDefault will throw trying // to assign null to an integer. In this instance we catch it and return the None type. @@ -209,7 +214,7 @@ public static CheckConclusion GetCheckConclusionForPullRequest(DataStore datasto StatusId = (long)CheckStatus.Completed, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); // Query results in NULL if there are no entries, and QueryFirstOrDefault will throw trying // to assign null to an integer. In this instance we catch it and return the None type. @@ -230,9 +235,9 @@ public static void DeleteAllForPullRequest(DataStore dataStore, PullRequest pull var command = dataStore.Connection!.CreateCommand(); command.CommandText = sql; command.Parameters.AddWithValue("$HeadSha", pullRequest.HeadSha); - Log.Logger()?.ReportDebug(DataStore.GetCommandLogMessage(sql, command)); + Log.Verbose(DataStore.GetCommandLogMessage(sql, command)); var rowsDeleted = command.ExecuteNonQuery(); - Log.Logger()?.ReportDebug(DataStore.GetDeletedLogMessage(rowsDeleted)); + Log.Verbose(DataStore.GetDeletedLogMessage(rowsDeleted)); } public static void DeleteUnreferenced(DataStore dataStore) @@ -241,7 +246,7 @@ public static void DeleteUnreferenced(DataStore dataStore) var sql = @"DELETE FROM CheckSuite WHERE HeadSha NOT IN (SELECT HeadSha FROM PullRequest)"; var command = dataStore.Connection!.CreateCommand(); command.CommandText = sql; - Log.Logger()?.ReportDebug(DataStore.GetCommandLogMessage(sql, command)); + Log.Verbose(DataStore.GetCommandLogMessage(sql, command)); command.ExecuteNonQuery(); } } diff --git a/src/GitHubExtension/DataModel/DataObjects/CommitCombinedStatus.cs b/src/GitHubExtension/DataModel/DataObjects/CommitCombinedStatus.cs index 267d905..3531b15 100644 --- a/src/GitHubExtension/DataModel/DataObjects/CommitCombinedStatus.cs +++ b/src/GitHubExtension/DataModel/DataObjects/CommitCombinedStatus.cs @@ -3,12 +3,17 @@ using Dapper; using Dapper.Contrib.Extensions; +using Serilog; namespace GitHubExtension.DataModel; [Table("CommitCombinedStatus")] public class CommitCombinedStatus { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", $"DataModel/{nameof(CommitCombinedStatus)}")); + + private static readonly ILogger Log = _log.Value; + [Key] public long Id { get; set; } = DataStore.NoForeignKey; @@ -71,7 +76,7 @@ private static CommitState GetCommitState(Octokit.StringEnum _log = new(() => Serilog.Log.ForContext("SourceContext", $"DataModel/{nameof(Issue)}")); + + private static readonly ILogger Log = _log.Value; + [Key] public long Id { get; set; } = DataStore.NoForeignKey; @@ -286,7 +291,7 @@ public static IEnumerable GetAllForRepository(DataStore dataStore, Reposi RepositoryId = repository.Id, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); var issues = dataStore.Connection!.Query(sql, param, null) ?? Enumerable.Empty(); foreach (var issue in issues) { @@ -310,7 +315,7 @@ public static IEnumerable GetForSearch(DataStore dataStore, Search search SearchId = search.Id, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); var issues = dataStore.Connection!.Query(sql, param, null) ?? Enumerable.Empty(); foreach (var issue in issues) { @@ -365,8 +370,8 @@ public static void DeleteLastObservedBefore(DataStore dataStore, long repository command.CommandText = sql; command.Parameters.AddWithValue("$Time", date.ToDataStoreInteger()); command.Parameters.AddWithValue("$RepositoryId", repositoryId); - Log.Logger()?.ReportDebug(DataStore.GetCommandLogMessage(sql, command)); + Log.Verbose(DataStore.GetCommandLogMessage(sql, command)); var rowsDeleted = command.ExecuteNonQuery(); - Log.Logger()?.ReportDebug(DataStore.GetDeletedLogMessage(rowsDeleted)); + Log.Verbose(DataStore.GetDeletedLogMessage(rowsDeleted)); } } diff --git a/src/GitHubExtension/DataModel/DataObjects/IssueAssign.cs b/src/GitHubExtension/DataModel/DataObjects/IssueAssign.cs index 578ab91..2bbc9d8 100644 --- a/src/GitHubExtension/DataModel/DataObjects/IssueAssign.cs +++ b/src/GitHubExtension/DataModel/DataObjects/IssueAssign.cs @@ -3,12 +3,17 @@ using Dapper; using Dapper.Contrib.Extensions; +using Serilog; namespace GitHubExtension.DataModel; [Table("IssueAssign")] public class IssueAssign { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", $"DataModel/{nameof(IssueAssign)}")); + + private static readonly ILogger Log = _log.Value; + [Key] public long Id { get; set; } = DataStore.NoForeignKey; @@ -55,7 +60,7 @@ public static IEnumerable GetUsersForIssue(DataStore dataStore, Issue issu IssueId = issue.Id, }; - Log.Logger()?.ReportDebug(DataStore.GetSqlLogMessage(sql, param)); + Log.Verbose(DataStore.GetSqlLogMessage(sql, param)); return dataStore.Connection!.Query(sql, param, null) ?? Enumerable.Empty(); } diff --git a/src/GitHubExtension/DataModel/DataObjects/IssueLabel.cs b/src/GitHubExtension/DataModel/DataObjects/IssueLabel.cs index 5ab44d4..86e3f92 100644 --- a/src/GitHubExtension/DataModel/DataObjects/IssueLabel.cs +++ b/src/GitHubExtension/DataModel/DataObjects/IssueLabel.cs @@ -3,12 +3,17 @@ using Dapper; using Dapper.Contrib.Extensions; +using Serilog; namespace GitHubExtension.DataModel; [Table("IssueLabel")] public class IssueLabel { + private static readonly Lazy _log = new(() => Serilog.Log.ForContext("SourceContext", $"DataModel/{nameof(IssueLabel)}")); + + private static readonly ILogger Log = _log.Value; + [Key] public long Id { get; set; } = DataStore.NoForeignKey; @@ -55,7 +60,7 @@ public static IEnumerable