Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add retry on specific git output #5747

Merged
merged 8 commits into from
Mar 22, 2023
Merged

Add retry on specific git output #5747

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
c593588
first cut at retry mechanism
scbedd Mar 17, 2023
5dc343d
add retry based on git output
scbedd Mar 18, 2023
e3ae96b
clean up usings
scbedd Mar 18, 2023
ddbf934
remove extraneous param in code summary
scbedd Mar 18, 2023
45a4e13
ensure we bomb out early
scbedd Mar 18, 2023
7e339e2
simplify the error handling. not certain why I complicated it so much…
scbedd Mar 22, 2023
0d771d1
add delay
scbedd Mar 22, 2023
33951c2
update retry count logic
scbedd Mar 22, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
56 changes: 56 additions & 0 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/GitProcessHandlerTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,62 @@ public GitProcessHandlerTests()
DebugLogger.ConfigureLogger(loggerFactory);
}

const string longTimeOutError = @"
Cloning into '.'...
fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443: Operation timed out


at Azure.Sdk.Tools.TestProxy.Store.GitStore.InitializeAssetsRepo(GitAssetsConfiguration config, Boolean forceInit) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 456
at Azure.Sdk.Tools.TestProxy.Store.GitStore.Restore(String pathToAssetsJson) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 152
at Azure.Sdk.Tools.TestProxy.Startup.Run(Object commandObj) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Startup.cs:line 154
at CommandLine.ParserResultExtensions.WithParsedAsync[T](ParserResult`1 result, Func`2 action)
at Azure.Sdk.Tools.TestProxy.Startup.Main(String[] args) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Startup.cs:line 67
at Azure.Sdk.Tools.TestProxy.Startup.<Main>(String[] args)";

const string tooManyRequestsError = @"fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': The requested URL returned error: 429
fatal: could not fetch 26bfd3d8ada54a78573cb64f6fa79c8d4a300c8c from promisor remote

at Azure.Sdk.Tools.TestProxy.Store.GitStore.CheckoutRepoAtConfig(GitAssetsConfiguration config) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 330
at Azure.Sdk.Tools.TestProxy.Store.GitStore.InitializeAssetsRepo(GitAssetsConfiguration config, Boolean forceInit) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 459
at Azure.Sdk.Tools.TestProxy.Store.GitStore.Restore(String pathToAssetsJson) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 152
at Azure.Sdk.Tools.TestProxy.RecordingHandler.RestoreAssetsJson(String assetsJson, Boolean forceCheckout) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs:line 164
at Azure.Sdk.Tools.TestProxy.RecordingHandler.StartPlaybackAsync(String sessionId, HttpResponse outgoingResponse, RecordingType mode, String assetsPath) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs:line 373
at Azure.Sdk.Tools.TestProxy.Playback.Start() in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs:line 46
at lambda_method37(Closure , Object )";

const string longTimeOutWithValue = @"fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443 after 21019 ms: Couldn't connect to server
fatal: could not fetch 87d05b71fcffcf3c7fa8e611bda09b505ff586a4 from promisor remote


at Azure.Sdk.Tools.TestProxy.Store.GitStore.CheckoutRepoAtConfig(GitAssetsConfiguration config) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 330
at Azure.Sdk.Tools.TestProxy.Store.GitStore.InitializeAssetsRepo(GitAssetsConfiguration config, Boolean forceInit) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 459
at Azure.Sdk.Tools.TestProxy.Store.GitStore.Restore(String pathToAssetsJson) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitStore.cs:line 152
at Azure.Sdk.Tools.TestProxy.RecordingHandler.RestoreAssetsJson(String assetsJson, Boolean forceCheckout) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs:line 164
at Azure.Sdk.Tools.TestProxy.RecordingHandler.StartPlaybackAsync(String sessionId, HttpResponse outgoingResponse, RecordingType mode, String assetsPath) in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/RecordingHandler.cs:line 373
at Azure.Sdk.Tools.TestProxy.Playback.Start() in /mnt/vss/_work/1/s/tools/test-proxy/Azure.Sdk.Tools.TestProxy/Playback.cs:line 46
at lambda_method37(Closure , Object )";

[Theory]
[InlineData("", longTimeOutError, 1, true)]
[InlineData("", tooManyRequestsError, 1, true)]
[InlineData("", longTimeOutWithValue, 1, true)]
[InlineData("", "fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443 after 1 ms: Couldn't connect to server", 1, true)]
[InlineData("", "fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443 after 0 ms: Couldn't connect to server", 1, true)]
[InlineData("", "fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443 after ms: Couldn't connect to server", 1, false)]
[InlineData("", "", 0, false)]
public void VerifyGitExceptionParser(string inputStdOut, string inputStdErr, int exitCode, bool expectedResult)
{
var processHandler = new GitProcessHandler();
var commandResult = new CommandResult();
commandResult.StdOut = inputStdOut;
commandResult.StdErr = inputStdErr;
commandResult.ExitCode = exitCode;

var checkResult = processHandler.IsRetriableGitError(commandResult);

Assert.Equal(expectedResult, checkResult);
}

[Theory]
// 2.37.0 is the min version of git required by the TestProxy
// Windows git version strings
Expand Down
229 changes: 157 additions & 72 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy/Store/GitProcessHandler.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,4 @@
using System;
using System.Collections;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Diagnostics;
Expand All @@ -21,11 +20,13 @@ public class CommandResult
public Exception CommandException;
}


/// <summary>
/// This class offers an easy wrapper abstraction for shelling out to git.
/// </summary>
public class GitProcessHandler
{
public const int RETRY_INTERMITTENT_FAILURE_COUNT = 3;
/// <summary>
/// Internal class to hold the minimum supported version of git. If that
/// version changes we only need to change it here.
Expand Down Expand Up @@ -127,54 +128,73 @@ public virtual CommandResult Run(string arguments, string workingDirectory)
{
try
{
DebugLogger.LogInformation($"git {arguments}");

var output = new List<string>();
var error = new List<string>();

using (var process = new Process())
int attempts = 1;
while (attempts <= RETRY_INTERMITTENT_FAILURE_COUNT)
{
process.StartInfo = processStartInfo;
DebugLogger.LogInformation($"git {arguments}");

var output = new List<string>();
var error = new List<string>();

process.OutputDataReceived += (s, e) =>
using (var process = new Process())
{
lock (output)
process.StartInfo = processStartInfo;

process.OutputDataReceived += (s, e) =>
{
output.Add(e.Data);
}
};
lock (output)
{
output.Add(e.Data);
}
};

process.ErrorDataReceived += (s, e) =>
{
lock (error)
process.ErrorDataReceived += (s, e) =>
{
error.Add(e.Data);
lock (error)
{
error.Add(e.Data);
}
};

process.Start();
process.BeginErrorReadLine();
process.BeginOutputReadLine();
process.WaitForExit();

int returnCode = process.ExitCode;
var stdOut = string.Join(Environment.NewLine, output);
var stdError = string.Join(Environment.NewLine, error);

DebugLogger.LogDebug($"StdOut: {stdOut}");
DebugLogger.LogDebug($"StdErr: {stdError}");
DebugLogger.LogDebug($"ExitCode: {process.ExitCode}");

result.ExitCode = process.ExitCode;
result.StdErr = string.Join(Environment.NewLine, stdError);
result.StdOut = string.Join(Environment.NewLine, stdOut);

if (result.ExitCode == 0)
{
break;
}
};

process.Start();
process.BeginErrorReadLine();
process.BeginOutputReadLine();
process.WaitForExit();

int returnCode = process.ExitCode;
var stdOut = string.Join(Environment.NewLine, output);
var stdError = string.Join(Environment.NewLine, error);
var continueToAttempt = IsRetriableGitError(result);

DebugLogger.LogDebug($"StdOut: {stdOut}");
DebugLogger.LogDebug($"StdErr: {stdError}");
DebugLogger.LogDebug($"ExitCode: {process.ExitCode}");
if (!continueToAttempt)
{
throw new GitProcessException(result);
}

result.ExitCode = process.ExitCode;
result.StdErr = string.Join(Environment.NewLine, stdError);
result.StdOut = string.Join(Environment.NewLine, stdOut);
attempts++;

if (result.ExitCode != 0)
{
throw new GitProcessException(result);
if (continueToAttempt && attempts < RETRY_INTERMITTENT_FAILURE_COUNT)
{
Task.Delay(attempts * 2 * 1000).Wait();
}
}
}
}
// exceptions caught here will be to do with inability to start the git process
// otherwise all "error" states should be handled by the output to stdErr and non-zero exitcode.
catch (Exception e)
{
DebugLogger.LogDebug(e.Message);
Expand All @@ -189,6 +209,52 @@ public virtual CommandResult Run(string arguments, string workingDirectory)
return result;
}

/// <summary>
/// This function evaluates a git command invocation result. The result of "yes you should retry this" only occurs
/// when the necessary data is available. Otherwise we default to NOT retry.
///
/// Check Azure/azure-sdk-tools#5660 for additional detail on occurrence.
/// </summary>
/// <param name="result"></param>
/// <returns></returns>
public bool IsRetriableGitError(CommandResult result)
{
if (result.ExitCode != 0) {
// we cannot evaluate an empty stderr to see if it is retriable
if (string.IsNullOrEmpty(result.StdErr))
{
return false;
}

// fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': The requested URL returned error: 429
if (result.StdErr.Contains("The requested URL returned error: 429"))
{
return true;
}

// fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443: Connection timed out
if (result.StdErr.Contains("Failed to connect to github.com port 443: Connection timed out"))
{
return true;
}

// fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443: Operation timed out
if (result.StdErr.Contains("Failed to connect to github.com port 443: Operation timed out"))
{
return true;
}

// fatal: unable to access 'https://github.com/Azure/azure-sdk-assets/': Failed to connect to github.com port 443 after 21019 ms: Couldn't connect to server
var regex = new Regex(@"Failed to connect to github.com port 443 after [\d]+ ms: Couldn't connect to server");
if (regex.IsMatch(result.StdErr))
{
return true;
}
}

return false;
}

/// <summary>
/// Invokes git binary against a GitAssetsConfiguration.
/// </summary>
Expand All @@ -214,52 +280,71 @@ public virtual bool TryRun(string arguments, string workingDirectory, out Comman
{
try
{
DebugLogger.LogInformation($"git {arguments}");
var output = new List<string>();
var error = new List<string>();

using (var process = new Process())
int attempts = 1;
bool continueToAttempt = true;
while (continueToAttempt && attempts <= RETRY_INTERMITTENT_FAILURE_COUNT)
{
process.StartInfo = processStartInfo;
DebugLogger.LogInformation($"git {arguments}");
var output = new List<string>();
var error = new List<string>();

process.OutputDataReceived += (s, e) =>
using (var process = new Process())
{
lock (output)
{
output.Add(e.Data);
}
};
process.StartInfo = processStartInfo;

process.ErrorDataReceived += (s, e) =>
{
lock (error)
process.OutputDataReceived += (s, e) =>
{
error.Add(e.Data);
}
};
lock (output)
{
output.Add(e.Data);
}
};

process.Start();
process.BeginErrorReadLine();
process.BeginOutputReadLine();
process.WaitForExit();

int returnCode = process.ExitCode;
var stdOut = string.Join(Environment.NewLine, output);
var stdError = string.Join(Environment.NewLine, error);
process.ErrorDataReceived += (s, e) =>
{
lock (error)
{
error.Add(e.Data);
}
};

process.Start();
process.BeginErrorReadLine();
process.BeginOutputReadLine();
process.WaitForExit();

int returnCode = process.ExitCode;
var stdOut = string.Join(Environment.NewLine, output);
var stdError = string.Join(Environment.NewLine, error);

DebugLogger.LogDebug($"StdOut: {stdOut}");
DebugLogger.LogDebug($"StdErr: {stdError}");
DebugLogger.LogDebug($"ExitCode: {process.ExitCode}");

commandResult = new CommandResult()
{
ExitCode = process.ExitCode,
StdErr = stdError,
StdOut = stdOut,
Arguments = arguments
};

DebugLogger.LogDebug($"StdOut: {stdOut}");
DebugLogger.LogDebug($"StdErr: {stdError}");
DebugLogger.LogDebug($"ExitCode: {process.ExitCode}");
if (commandResult.ExitCode == 0)
{
break;
}
continueToAttempt = IsRetriableGitError(commandResult);

commandResult = new CommandResult()
{
ExitCode = process.ExitCode,
StdErr = stdError,
StdOut = stdOut,
Arguments = arguments
};
attempts++;
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

for @benbp

enter loop, attempts = 1
invoke command, continueToAttempt = true
attempts = 2
delay 4 seconds because continueToAttempt = true
invoke command, continueToAttempts = true
attempts = 3
delay 6 seconds because continueToAttempt = true
invoke command, continueToAttempts = true
attempts = 4
we do not delay before exiting the loop, because 4 is not < max retry count and we won't be retrying anyway

For a grand total of 3 attempts, 2 retries. I'm good with this to start.

if (continueToAttempt && attempts < RETRY_INTERMITTENT_FAILURE_COUNT)
{
Task.Delay(attempts * 2 * 1000).Wait();
}
}
}
}
// exceptions caught here will be to do with inability to start the git process
// otherwise all "error" states should be handled by the output to stdErr and non-zero exitcode.
catch (Exception e)
{
DebugLogger.LogDebug(e.Message);
Expand Down