github / gh-gei

Migration CLI for GitHub to GitHub migrations
MIT License
308 stars 82 forks source link

Don't retry queries on NOT_FOUND errors #975

Open aliwojo opened 1 year ago

aliwojo commented 1 year ago

We have gotten complaints from users that the generate-mannequins-csv command takes to long to raise an error if an invalid org name is provided for --github-target-org. Based on the verbose logs, it seems we are retrying the query to find the organization 5 times before raising the error. @timrogers has suggested that retries be skipped for "NOT_FOUND" errors so the command can fail fast.

Verbose logs for context:

aliwojo@Alis-MBP-2 ~ % gh gei generate-mannequin-csv --github-target-org notavalidorg --verbose
[4:57 PM] [INFO] You are running the latest version of the gei CLI [v0.41]
[4:57 PM] [INFO] Generating CSV...
[4:57 PM] [INFO] GITHUB ORG: notavalidorg
[4:57 PM] [INFO] OUTPUT: ./mannequins.csv
[4:57 PM] [DEBUG] HTTP POST: https://api.github.com/graphql
[4:57 PM] [DEBUG] HTTP BODY: {"query":"query($login: String!) {organization(login: $login) { login, id, name } }","variables":{"login":"notavalidorg"}}
[4:57 PM] [DEBUG] GITHUB REQUEST ID: C18C:0E94:3421A:6D00D:64557BB3
[4:57 PM] [DEBUG] RESPONSE (OK): {"data":{"organization":null},"errors":[{"type":"NOT_FOUND","path":["organization"],"locations":[{"line":1,"column":25}],"message":"Could not resolve to an Organization with the login of 'notavalidorg'."}]}
[4:57 PM] [DEBUG] OctoshiftCLI.OctoshiftCliException: Could not resolve to an Organization with the login of 'notavalidorg'.
   at OctoshiftCLI.Services.GithubClient.EnsureSuccessGraphQLResponse(JObject response)
   at OctoshiftCLI.Services.GithubClient.PostGraphQLAsync(String url, Object body, Dictionary`2 customHeaders)
   at OctoshiftCLI.Services.GithubApi.<>c__DisplayClass17_0.<<GetOrganizationId>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Polly.Retry.AsyncRetryEngine.ImplementationAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, ExceptionPredicates shouldRetryExceptionPredicates, ResultPredicates`1 shouldRetryResultPredicates, Func`5 onRetryAsync, Int32 permittedRetryCount, IEnumerable`1 sleepDurationsEnumerable, Func`4 sleepDurationProvider, Boolean continueOnCapturedContext)
[4:57 PM] [DEBUG] Retrying...
[4:57 PM] [DEBUG] HTTP POST: https://api.github.com/graphql
[4:57 PM] [DEBUG] HTTP BODY: {"query":"query($login: String!) {organization(login: $login) { login, id, name } }","variables":{"login":"notavalidorg"}}
[4:57 PM] [DEBUG] GITHUB REQUEST ID: C18C:0E94:346D0:6D9EE:64557BB7
[4:57 PM] [DEBUG] RESPONSE (OK): {"data":{"organization":null},"errors":[{"type":"NOT_FOUND","path":["organization"],"locations":[{"line":1,"column":25}],"message":"Could not resolve to an Organization with the login of 'notavalidorg'."}]}
[4:57 PM] [DEBUG] OctoshiftCLI.OctoshiftCliException: Could not resolve to an Organization with the login of 'notavalidorg'.
   at OctoshiftCLI.Services.GithubClient.EnsureSuccessGraphQLResponse(JObject response)
   at OctoshiftCLI.Services.GithubClient.PostGraphQLAsync(String url, Object body, Dictionary`2 customHeaders)
   at OctoshiftCLI.Services.GithubApi.<>c__DisplayClass17_0.<<GetOrganizationId>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Polly.Retry.AsyncRetryEngine.ImplementationAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, ExceptionPredicates shouldRetryExceptionPredicates, ResultPredicates`1 shouldRetryResultPredicates, Func`5 onRetryAsync, Int32 permittedRetryCount, IEnumerable`1 sleepDurationsEnumerable, Func`4 sleepDurationProvider, Boolean continueOnCapturedContext)
[4:57 PM] [DEBUG] Retrying...
[4:57 PM] [DEBUG] HTTP POST: https://api.github.com/graphql
[4:57 PM] [DEBUG] HTTP BODY: {"query":"query($login: String!) {organization(login: $login) { login, id, name } }","variables":{"login":"notavalidorg"}}
[4:57 PM] [DEBUG] GITHUB REQUEST ID: C18C:0E94:34F32:6EB5B:64557BBF
[4:57 PM] [DEBUG] RESPONSE (OK): {"data":{"organization":null},"errors":[{"type":"NOT_FOUND","path":["organization"],"locations":[{"line":1,"column":25}],"message":"Could not resolve to an Organization with the login of 'notavalidorg'."}]}
[4:57 PM] [DEBUG] OctoshiftCLI.OctoshiftCliException: Could not resolve to an Organization with the login of 'notavalidorg'.
   at OctoshiftCLI.Services.GithubClient.EnsureSuccessGraphQLResponse(JObject response)
   at OctoshiftCLI.Services.GithubClient.PostGraphQLAsync(String url, Object body, Dictionary`2 customHeaders)
   at OctoshiftCLI.Services.GithubApi.<>c__DisplayClass17_0.<<GetOrganizationId>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Polly.Retry.AsyncRetryEngine.ImplementationAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, ExceptionPredicates shouldRetryExceptionPredicates, ResultPredicates`1 shouldRetryResultPredicates, Func`5 onRetryAsync, Int32 permittedRetryCount, IEnumerable`1 sleepDurationsEnumerable, Func`4 sleepDurationProvider, Boolean continueOnCapturedContext)
[4:57 PM] [DEBUG] Retrying...
[4:57 PM] [DEBUG] HTTP POST: https://api.github.com/graphql
[4:57 PM] [DEBUG] HTTP BODY: {"query":"query($login: String!) {organization(login: $login) { login, id, name } }","variables":{"login":"notavalidorg"}}
[4:57 PM] [DEBUG] GITHUB REQUEST ID: C18C:0E94:35C85:706EB:64557BCC
[4:57 PM] [DEBUG] RESPONSE (OK): {"data":{"organization":null},"errors":[{"type":"NOT_FOUND","path":["organization"],"locations":[{"line":1,"column":25}],"message":"Could not resolve to an Organization with the login of 'notavalidorg'."}]}
[4:57 PM] [DEBUG] OctoshiftCLI.OctoshiftCliException: Could not resolve to an Organization with the login of 'notavalidorg'.
   at OctoshiftCLI.Services.GithubClient.EnsureSuccessGraphQLResponse(JObject response)
   at OctoshiftCLI.Services.GithubClient.PostGraphQLAsync(String url, Object body, Dictionary`2 customHeaders)
   at OctoshiftCLI.Services.GithubApi.<>c__DisplayClass17_0.<<GetOrganizationId>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Polly.Retry.AsyncRetryEngine.ImplementationAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, ExceptionPredicates shouldRetryExceptionPredicates, ResultPredicates`1 shouldRetryResultPredicates, Func`5 onRetryAsync, Int32 permittedRetryCount, IEnumerable`1 sleepDurationsEnumerable, Func`4 sleepDurationProvider, Boolean continueOnCapturedContext)
[4:57 PM] [DEBUG] Retrying...
[4:57 PM] [DEBUG] HTTP POST: https://api.github.com/graphql
[4:57 PM] [DEBUG] HTTP BODY: {"query":"query($login: String!) {organization(login: $login) { login, id, name } }","variables":{"login":"notavalidorg"}}
[4:57 PM] [DEBUG] GITHUB REQUEST ID: C18C:0E94:36F2E:72D04:64557BDC
[4:57 PM] [DEBUG] RESPONSE (OK): {"data":{"organization":null},"errors":[{"type":"NOT_FOUND","path":["organization"],"locations":[{"line":1,"column":25}],"message":"Could not resolve to an Organization with the login of 'notavalidorg'."}]}
[4:57 PM] [DEBUG] OctoshiftCLI.OctoshiftCliException: Could not resolve to an Organization with the login of 'notavalidorg'.
   at OctoshiftCLI.Services.GithubClient.EnsureSuccessGraphQLResponse(JObject response)
   at OctoshiftCLI.Services.GithubClient.PostGraphQLAsync(String url, Object body, Dictionary`2 customHeaders)
   at OctoshiftCLI.Services.GithubApi.<>c__DisplayClass17_0.<<GetOrganizationId>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Polly.Retry.AsyncRetryEngine.ImplementationAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, ExceptionPredicates shouldRetryExceptionPredicates, ResultPredicates`1 shouldRetryResultPredicates, Func`5 onRetryAsync, Int32 permittedRetryCount, IEnumerable`1 sleepDurationsEnumerable, Func`4 sleepDurationProvider, Boolean continueOnCapturedContext)
[4:57 PM] [DEBUG] Retrying...
[4:58 PM] [DEBUG] HTTP POST: https://api.github.com/graphql
[4:58 PM] [DEBUG] HTTP BODY: {"query":"query($login: String!) {organization(login: $login) { login, id, name } }","variables":{"login":"notavalidorg"}}
[4:58 PM] [DEBUG] GITHUB REQUEST ID: C18C:0E94:3879E:75F82:64557BF0
[4:58 PM] [DEBUG] RESPONSE (OK): {"data":{"organization":null},"errors":[{"type":"NOT_FOUND","path":["organization"],"locations":[{"line":1,"column":25}],"message":"Could not resolve to an Organization with the login of 'notavalidorg'."}]}
[4:58 PM] [ERROR] OctoshiftCLI.OctoshiftCliException: Failed to lookup the Organization ID for organization 'notavalidorg'
 ---> OctoshiftCLI.OctoshiftCliException: Could not resolve to an Organization with the login of 'notavalidorg'.
   at OctoshiftCLI.Services.GithubClient.EnsureSuccessGraphQLResponse(JObject response)
   at OctoshiftCLI.Services.GithubClient.PostGraphQLAsync(String url, Object body, Dictionary`2 customHeaders)
   at OctoshiftCLI.Services.GithubApi.<>c__DisplayClass17_0.<<GetOrganizationId>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Polly.Retry.AsyncRetryEngine.ImplementationAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, ExceptionPredicates shouldRetryExceptionPredicates, ResultPredicates`1 shouldRetryResultPredicates, Func`5 onRetryAsync, Int32 permittedRetryCount, IEnumerable`1 sleepDurationsEnumerable, Func`4 sleepDurationProvider, Boolean continueOnCapturedContext)
   at Polly.AsyncPolicy.ExecuteAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, Boolean continueOnCapturedContext)
   at OctoshiftCLI.RetryPolicy.Retry[T](Func`1 func)
   at OctoshiftCLI.Services.GithubApi.GetOrganizationId(String org)
   --- End of inner exception stack trace ---
   at OctoshiftCLI.Services.GithubApi.GetOrganizationId(String org)
   at OctoshiftCLI.Handlers.GenerateMannequinCsvCommandHandler.Handle(GenerateMannequinCsvCommandArgs args)
   at OctoshiftCLI.Extensions.CommandExtensions.<>c__DisplayClass1_0`3.<<ConfigureCommand>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Invocation.AnonymousCommandHandler.InvokeAsync(InvocationContext )
   at System.CommandLine.Invocation.InvocationPipeline.<>c__DisplayClass4_0.<<BuildInvocationChain>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass17_0.<<UseParseErrorReporting>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass12_0.<<UseHelp>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<<UseVersionOption>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass19_0.<<UseTypoCorrections>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<UseSuggestDirective>b__18_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass16_0.<<UseParseDirective>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<<RegisterWithDotnetSuggest>b__5_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass8_0.<<UseExceptionHandler>b__0>d.MoveNext()
dylan-smith commented 1 year ago

FYI this retry logic was added in this PR: #686

timrogers commented 1 year ago

Nice! We'll want to keep retries, but just be a bit more selective about when they happen. I'm aware that that might be difficult, as we'll need to figure out what errors are worth retrying. We should probably just retry connection errors and the GraphQL timeout error (which I can find an example of next week).