Skip to content

Commit

Permalink
Add retry on specific git output (#5747)
Browse files Browse the repository at this point in the history 
* add retry based on git output. error 429 and timeouts are now retried twice before we give up
  • Loading branch information
@scbedd
scbedd authored Mar 22, 2023
1 parent e91878a commit 5390bfe
Show file tree
Hide file tree
Showing 2 changed files with 213 additions and 72 deletions.
56 changes: 56 additions & 0 deletions tools/test-proxy/Azure.Sdk.Tools.TestProxy.Tests/GitProcessHandlerTests.cs
View file
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
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++;
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

0 comments on commit 5390bfe

Please sign in to comment.