From 70be3b83dbf837ed62cd6e42a78155bed84b293e Mon Sep 17 00:00:00 2001 From: Satu Bailey <24945574+satbai@users.noreply.github.com> Date: Thu, 14 Feb 2019 11:29:33 -0800 Subject: [PATCH] Add more verbose logging (#67) * Adding more verbose logs --- Build.props | 2 +- .../VstsBuildTaskCredentialProvider.cs | 5 ++- ...ldTaskServiceEndpointCredentialProvider.cs | 2 + .../RequestHandlers/RequestHandlerBase.cs | 10 +++-- .../Resources.Designer.cs | 38 ++++++++++++++++++- CredentialProvider.Microsoft/Resources.resx | 14 ++++++- 6 files changed, 64 insertions(+), 7 deletions(-) diff --git a/Build.props b/Build.props index ebefaaf9..fe1b576e 100644 --- a/Build.props +++ b/Build.props @@ -1,6 +1,6 @@ - 0.1.11 + 0.1.12 \ No newline at end of file diff --git a/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs b/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs index 46e97f9d..dc953563 100644 --- a/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs +++ b/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs @@ -49,6 +49,8 @@ public override Task HandleRequestAsync(Ge string uriPrefixesString = Environment.GetEnvironmentVariable(EnvUtil.BuildTaskUriPrefixes); string accessToken = Environment.GetEnvironmentVariable(EnvUtil.BuildTaskAccessToken); + Verbose(string.Format(Resources.IsRetry, request.IsRetry)); + string[] uriPrefixes = uriPrefixesString.Split(new[] { ';' }, StringSplitOptions.RemoveEmptyEntries); Verbose(Resources.BuildTaskUriPrefixes); foreach (var uriPrefix in uriPrefixes) @@ -58,7 +60,7 @@ public override Task HandleRequestAsync(Ge string uriString = request.Uri.ToString(); string matchedPrefix = uriPrefixes.FirstOrDefault(prefix => uriString.StartsWith(prefix, StringComparison.OrdinalIgnoreCase)); - Verbose(string.Format(Resources.BuildTaskMatchedPrefix, matchedPrefix)); + Verbose(string.Format(Resources.BuildTaskMatchedPrefix, matchedPrefix != null ? matchedPrefix : Resources.BuildTaskNoMatchingPrefixes)); if (matchedPrefix == null) { @@ -70,6 +72,7 @@ public override Task HandleRequestAsync(Ge MessageResponseCode.Error); } + Verbose(string.Format(Resources.BuildTaskEndpointMatchingUrlFound, uriString)); return this.GetResponse( Username, accessToken, diff --git a/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTaskServiceEndpoint/VstsBuildTaskServiceEndpointCredentialProvider.cs b/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTaskServiceEndpoint/VstsBuildTaskServiceEndpointCredentialProvider.cs index e1e3397f..4f925acc 100644 --- a/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTaskServiceEndpoint/VstsBuildTaskServiceEndpointCredentialProvider.cs +++ b/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTaskServiceEndpoint/VstsBuildTaskServiceEndpointCredentialProvider.cs @@ -65,6 +65,8 @@ public override Task HandleRequestAsync(Ge { cancellationToken.ThrowIfCancellationRequested(); + Verbose(string.Format(Resources.IsRetry, request.IsRetry)); + string uriString = request.Uri.ToString(); bool endpointFound = Credentials.TryGetValue(uriString, out EndpointCredentials matchingEndpoint); if (endpointFound) diff --git a/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs b/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs index 48479640..61994fb4 100644 --- a/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs +++ b/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs @@ -64,16 +64,19 @@ public async Task HandleResponseAsync(IConnection connection, Message message, I } catch (Exception ex) when (cancellationToken.IsCancellationRequested) { + Logger.Verbose(string.Format(Resources.RequestHandlerCancelingExceptionMessage, ex.InnerException, ex.Message)); + Logger.Verbose(Resources.CancellationRequested); + // We have been canceled by NuGet. Send a cancellation response. var cancelMessage = MessageUtilities.Create(message.RequestId, MessageType.Cancel, message.Method); await connection.SendAsync(cancelMessage, CancellationToken.None); - - Logger.Verbose(ex.ToString()); - + // We must guarantee that exactly one terminating message is sent, so do not fall through to send // the normal response, but also do not rethrow. return; } + + Logger.Verbose(string.Format(Resources.SendingResponse, message.Type, message.Method)); // If we did not send a cancel message, we must submit the response even if cancellationToken is canceled. await responseHandler.SendResponseAsync(message, response, CancellationToken.None).ConfigureAwait(continueOnCapturedContext: false); } @@ -87,6 +90,7 @@ bool LogExceptionAndReturnFalse(Exception ex) // don't report cancellations during shutdown, they're most likely not interesting. if (ex is OperationCanceledException && Program.IsShuttingDown && !Debugger.IsAttached) { + Logger.Verbose(Resources.ShuttingDown); return false; } diff --git a/CredentialProvider.Microsoft/Resources.Designer.cs b/CredentialProvider.Microsoft/Resources.Designer.cs index 95f25f1f..2fc54ad0 100644 --- a/CredentialProvider.Microsoft/Resources.Designer.cs +++ b/CredentialProvider.Microsoft/Resources.Designer.cs @@ -238,6 +238,15 @@ internal static string BuildTaskMatchedPrefix { } } + /// + /// Looks up a localized string similar to none. + /// + internal static string BuildTaskNoMatchingPrefixes { + get { + return ResourceManager.GetString("BuildTaskNoMatchingPrefixes", resourceCulture); + } + } + /// /// Looks up a localized string similar to This provider only handles URIs from the build's Team Project Collection. /// @@ -283,6 +292,15 @@ internal static string CachingSessionToken { } } + /// + /// Looks up a localized string similar to Cancellation requested. Sending cancellation response.. + /// + internal static string CancellationRequested { + get { + return ResourceManager.GetString("CancellationRequested", resourceCulture); + } + } + /// /// Looks up a localized string similar to Canceling credential provider. /// @@ -559,6 +577,15 @@ internal static string Redacted { } } + /// + /// Looks up a localized string similar to Cancellation exception happened while handling request. Exception: {0}, Message: {1}. + /// + internal static string RequestHandlerCancelingExceptionMessage { + get { + return ResourceManager.GetString("RequestHandlerCancelingExceptionMessage", resourceCulture); + } + } + /// /// Looks up a localized string similar to Request uri cannot be null. /// @@ -596,7 +623,7 @@ internal static string RunningInStandAlone { } /// - /// Looks up a localized string similar to Sending response: '{0}'. + /// Looks up a localized string similar to Sending response: '{0}' '{1}'. /// internal static string SendingResponse { get { @@ -622,6 +649,15 @@ internal static string SessionTokenCacheLocation { } } + /// + /// Looks up a localized string similar to Credential provider shutting down.. + /// + internal static string ShuttingDown { + get { + return ResourceManager.GetString("ShuttingDown", resourceCulture); + } + } + /// /// Looks up a localized string similar to Skipping {0}, cannot provide credentials for {1}. /// diff --git a/CredentialProvider.Microsoft/Resources.resx b/CredentialProvider.Microsoft/Resources.resx index d7301246..4bca14d0 100644 --- a/CredentialProvider.Microsoft/Resources.resx +++ b/CredentialProvider.Microsoft/Resources.resx @@ -230,7 +230,7 @@ Running in stand-alone mode - Sending response: '{0}' + Sending response: '{0}' '{1}' SessionToken cache disabled by environment @@ -418,4 +418,16 @@ Device Flow Authentication Timeout Exception happened when trying to get cached token. Invalidating cache. Message: {0} + + Cancellation requested. Sending cancellation response. + + + none + + + Cancellation exception happened while handling request. Exception: {0}, Message: {1} + + + Credential provider shutting down. + \ No newline at end of file