From 846750b6f90a41e2b8f1cca422ebe548b2a7f0b3 Mon Sep 17 00:00:00 2001 From: Satu Bailey <24945574+satbai@users.noreply.github.com> Date: Thu, 14 Feb 2019 09:07:57 -0800 Subject: [PATCH 1/3] Adding more verbose logs --- .../VstsBuildTaskCredentialProvider.cs | 5 ++- ...ldTaskServiceEndpointCredentialProvider.cs | 2 ++ .../RequestHandlers/RequestHandlerBase.cs | 8 +++-- .../Resources.Designer.cs | 36 +++++++++++++++++++ CredentialProvider.Microsoft/Resources.resx | 12 +++++++ 5 files changed, 59 insertions(+), 4 deletions(-) diff --git a/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs b/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs index 46e97f9d..b6b5a013 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.NoMatches)); 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..576b7c63 100644 --- a/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs +++ b/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs @@ -64,12 +64,13 @@ 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; @@ -87,6 +88,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..52e387b1 100644 --- a/CredentialProvider.Microsoft/Resources.Designer.cs +++ b/CredentialProvider.Microsoft/Resources.Designer.cs @@ -283,6 +283,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. /// @@ -514,6 +523,15 @@ internal static string NoEndpointsFound { } } + /// + /// Looks up a localized string similar to none. + /// + internal static string NoMatches { + get { + return ResourceManager.GetString("NoMatches", resourceCulture); + } + } + /// /// Looks up a localized string similar to Not running bearer token provider '{0}'. /// @@ -559,6 +577,15 @@ internal static string Redacted { } } + /// + /// Looks up a localized string similar to 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. /// @@ -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..2bb3f32b 100644 --- a/CredentialProvider.Microsoft/Resources.resx +++ b/CredentialProvider.Microsoft/Resources.resx @@ -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 + + + Exception happened while handling request. Exception: {0}, Message: {1} + + + Credential provider shutting down. + \ No newline at end of file From 0994be892ccf35b8378290c287f0ee169be8447a Mon Sep 17 00:00:00 2001 From: Satu Bailey <24945574+satbai@users.noreply.github.com> Date: Thu, 14 Feb 2019 09:49:58 -0800 Subject: [PATCH 2/3] Bump version after adding more logging --- Build.props | 2 +- .../RequestHandlers/RequestHandlerBase.cs | 2 ++ CredentialProvider.Microsoft/Resources.Designer.cs | 2 +- CredentialProvider.Microsoft/Resources.resx | 2 +- 4 files changed, 5 insertions(+), 3 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/RequestHandlers/RequestHandlerBase.cs b/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs index 576b7c63..61994fb4 100644 --- a/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs +++ b/CredentialProvider.Microsoft/RequestHandlers/RequestHandlerBase.cs @@ -75,6 +75,8 @@ public async Task HandleResponseAsync(IConnection connection, Message message, I // 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); } diff --git a/CredentialProvider.Microsoft/Resources.Designer.cs b/CredentialProvider.Microsoft/Resources.Designer.cs index 52e387b1..3eebd90c 100644 --- a/CredentialProvider.Microsoft/Resources.Designer.cs +++ b/CredentialProvider.Microsoft/Resources.Designer.cs @@ -623,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 { diff --git a/CredentialProvider.Microsoft/Resources.resx b/CredentialProvider.Microsoft/Resources.resx index 2bb3f32b..bb1a975c 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 From 05047af0e4ffc4b24d6430c15732b873c554a25c Mon Sep 17 00:00:00 2001 From: Satu Bailey <24945574+satbai@users.noreply.github.com> Date: Thu, 14 Feb 2019 10:53:41 -0800 Subject: [PATCH 3/3] PR feedback --- .../VstsBuildTaskCredentialProvider.cs | 2 +- .../Resources.Designer.cs | 20 +++++++++---------- CredentialProvider.Microsoft/Resources.resx | 4 ++-- 3 files changed, 13 insertions(+), 13 deletions(-) diff --git a/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs b/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs index b6b5a013..dc953563 100644 --- a/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs +++ b/CredentialProvider.Microsoft/CredentialProviders/VstsBuildTask/VstsBuildTaskCredentialProvider.cs @@ -60,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 != null ? matchedPrefix : Resources.NoMatches)); + Verbose(string.Format(Resources.BuildTaskMatchedPrefix, matchedPrefix != null ? matchedPrefix : Resources.BuildTaskNoMatchingPrefixes)); if (matchedPrefix == null) { diff --git a/CredentialProvider.Microsoft/Resources.Designer.cs b/CredentialProvider.Microsoft/Resources.Designer.cs index 3eebd90c..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. /// @@ -523,15 +532,6 @@ internal static string NoEndpointsFound { } } - /// - /// Looks up a localized string similar to none. - /// - internal static string NoMatches { - get { - return ResourceManager.GetString("NoMatches", resourceCulture); - } - } - /// /// Looks up a localized string similar to Not running bearer token provider '{0}'. /// @@ -578,7 +578,7 @@ internal static string Redacted { } /// - /// Looks up a localized string similar to Exception happened while handling request. Exception: {0}, Message: {1}. + /// Looks up a localized string similar to Cancellation exception happened while handling request. Exception: {0}, Message: {1}. /// internal static string RequestHandlerCancelingExceptionMessage { get { diff --git a/CredentialProvider.Microsoft/Resources.resx b/CredentialProvider.Microsoft/Resources.resx index bb1a975c..4bca14d0 100644 --- a/CredentialProvider.Microsoft/Resources.resx +++ b/CredentialProvider.Microsoft/Resources.resx @@ -421,11 +421,11 @@ Device Flow Authentication Timeout Cancellation requested. Sending cancellation response. - + none - Exception happened while handling request. Exception: {0}, Message: {1} + Cancellation exception happened while handling request. Exception: {0}, Message: {1} Credential provider shutting down.