Skip to content

Commit 5d26fdc

Browse files
MpdreamzMpdreamz
committed
Add more logging to CLI invocations on CI and ensure CLI invocations have timeouts on CI
1 parent 95e743d commit 5d26fdc

File tree

6 files changed

+76
-66
lines changed

6 files changed

+76
-66
lines changed

‎src/Elastic.Documentation/ExternalCommands/ExternalCommandExecutor.cs‎

Lines changed: 49 additions & 53 deletions
Original file line numberDiff line numberDiff line change
@@ -4,20 +4,32 @@
44

55
using System.IO.Abstractions;
66
using Elastic.Documentation.Diagnostics;
7+
using Microsoft.Extensions.Logging;
78
using ProcNet;
9+
using ProcNet.Std;
810

911
namespace Elastic.Documentation.ExternalCommands;
1012

11-
public abstract class ExternalCommandExecutor(IDiagnosticsCollector collector, IDirectoryInfo workingDirectory)
13+
public abstract class ExternalCommandExecutor(IDiagnosticsCollector collector, IDirectoryInfo workingDirectory, TimeSpan? timeout = null)
1214
{
15+
protected abstract ILogger Logger { get; }
16+
17+
private void Log(Action<ILogger> logAction)
18+
{
19+
if (string.IsNullOrWhiteSpace(Environment.GetEnvironmentVariable("CI")))
20+
return;
21+
logAction(Logger);
22+
}
23+
1324
protected IDirectoryInfo WorkingDirectory => workingDirectory;
1425
protected IDiagnosticsCollector Collector => collector;
1526
protected void ExecIn(Dictionary<string, string> environmentVars, string binary, params string[] args)
1627
{
1728
var arguments = new ExecArguments(binary, args)
1829
{
1930
WorkingDirectory = workingDirectory.FullName,
20-
Environment = environmentVars
31+
Environment = environmentVars,
32+
Timeout = timeout
2133
};
2234
var result = Proc.Exec(arguments);
2335
if (result != 0)
@@ -30,99 +42,83 @@ protected void ExecInSilent(Dictionary<string, string> environmentVars, string b
3042
{
3143
Environment = environmentVars,
3244
WorkingDirectory = workingDirectory.FullName,
33-
ConsoleOutWriter = NoopConsoleWriter.Instance
45+
ConsoleOutWriter = NoopConsoleWriter.Instance,
46+
Timeout = timeout
3447
};
3548
var result = Proc.Start(arguments);
3649
if (result.ExitCode != 0)
3750
collector.EmitError("", $"Exit code: {result.ExitCode} while executing {binary} {string.Join(" ", args)} in {workingDirectory}");
3851
}
3952

4053
protected string[] CaptureMultiple(string binary, params string[] args) => CaptureMultiple(false, 10, binary, args);
41-
protected string[] CaptureMultiple(bool muteExceptions, int attempts, string binary, params string[] args)
54+
protected string[] CaptureMultiple(int attempts, string binary, params string[] args) => CaptureMultiple(false, attempts, binary, args);
55+
private string[] CaptureMultiple(bool muteExceptions, int attempts, string binary, params string[] args)
4256
{
4357
// Try 10 times to capture the output of the command, if it fails, we'll throw an exception on the last try
4458
Exception? e = null;
4559
for (var i = 1; i <= attempts; i++)
4660
{
4761
try
4862
{
49-
return CaptureOutput();
63+
return CaptureOutput(e, i, attempts);
5064
}
5165
catch (Exception ex)
5266
{
53-
collector.EmitWarning("", $"An exception occurred on attempt {i} to capture output of {binary}: {ex?.Message}");
67+
collector.EmitGlobalWarning($"An exception occurred on attempt {i} to capture output of {binary}: {ex?.Message}");
5468
if (ex is not null)
5569
e = ex;
5670
}
5771
}
5872

5973
if (e is not null && !muteExceptions)
6074
collector.EmitError("", "failure capturing stdout", e);
75+
if (e is not null)
76+
Log(l => l.LogError(e, "[{Binary} {Args}] failure capturing stdout executing in {WorkingDirectory}", binary, string.Join(" ", args), workingDirectory.FullName));
6177

6278
return [];
6379

64-
string[] CaptureOutput()
80+
string[] CaptureOutput(Exception? previousException, int iteration, int max)
6581
{
6682
var arguments = new StartArguments(binary, args)
6783
{
6884
WorkingDirectory = workingDirectory.FullName,
6985
Timeout = TimeSpan.FromSeconds(3),
7086
WaitForExit = TimeSpan.FromSeconds(3),
71-
ConsoleOutWriter = NoopConsoleWriter.Instance
87+
ConsoleOutWriter = new ConsoleOutWriter()
7288
};
7389
var result = Proc.Start(arguments);
7490

75-
var output = (result.ExitCode, muteExceptions) switch
91+
string[]? output;
92+
switch (result.ExitCode, muteExceptions)
7693
{
77-
(0, _) or (not 0, true) => result.ConsoleOut.Select(x => x.Line).ToArray() ?? throw new Exception($"No output captured for {binary}: {workingDirectory}"),
78-
(not 0, false) => throw new Exception($"Exit code is not 0. Received {result.ExitCode} from {binary}: {workingDirectory}")
79-
};
94+
case (0, _) or (not 0, true):
95+
output = result.ConsoleOut.Select(x => x.Line).ToArray();
96+
if (output.Length == 0)
97+
{
98+
Log(l => l.LogInformation("[{Binary} {Args}] captured no output. ({Iteration}/{MaxIteration}) pwd: {WorkingDirectory}",
99+
binary, string.Join(" ", args), iteration, max, workingDirectory.FullName)
100+
);
101+
throw new Exception($"No output captured executing in pwd: {workingDirectory} from {binary} {string.Join(" ", args)}", previousException);
102+
}
103+
break;
104+
case (not 0, false):
105+
Log(l => l.LogInformation("[{Binary} {Args}] Exit code is not 0 but {ExitCode}. ({Iteration}/{MaxIteration}) pwd: {WorkingDirectory}",
106+
binary, string.Join(" ", args), result.ExitCode, iteration, max, workingDirectory.FullName)
107+
);
108+
throw new Exception($"Exit code not 0. Received {result.ExitCode} in pwd: {workingDirectory} from {binary} {string.Join(" ", args)}", previousException);
109+
}
110+
80111
return output;
81112
}
82113
}
83114

84-
115+
protected string CaptureQuiet(string binary, params string[] args) => Capture(true, 10, binary, args);
85116
protected string Capture(string binary, params string[] args) => Capture(false, 10, binary, args);
86-
protected string Capture(bool muteExceptions, string binary, params string[] args) => Capture(muteExceptions, 10, binary, args);
87-
protected string Capture(bool muteExceptions, int attempts, string binary, params string[] args)
88-
{
89-
// Try 10 times to capture the output of the command, if it fails, we'll throw an exception on the last try
90-
Exception? e = null;
91-
for (var i = 1; i <= attempts; i++)
92-
{
93-
try
94-
{
95-
return CaptureOutput();
96-
}
97-
catch (Exception ex)
98-
{
99-
if (ex is not null)
100-
e = ex;
101-
}
102-
}
103-
104-
if (e is not null && !muteExceptions)
105-
collector.EmitError("", "failure capturing stdout", e);
106-
107-
return string.Empty;
108117

109-
string CaptureOutput()
110-
{
111-
var arguments = new StartArguments(binary, args)
112-
{
113-
WorkingDirectory = workingDirectory.FullName,
114-
Timeout = TimeSpan.FromSeconds(3),
115-
WaitForExit = TimeSpan.FromSeconds(3),
116-
ConsoleOutWriter = NoopConsoleWriter.Instance,
117-
OnlyPrintBinaryInExceptionMessage = false
118-
};
119-
var result = Proc.Start(arguments);
120-
var line = (result.ExitCode, muteExceptions) switch
121-
{
122-
(0, _) or (not 0, true) => result.ConsoleOut.FirstOrDefault()?.Line ?? throw new Exception($"No output captured for {binary}: {workingDirectory}"),
123-
(not 0, false) => throw new Exception($"Exit code is not 0. Received {result.ExitCode} from {binary}: {workingDirectory}")
124-
};
125-
return line;
126-
}
118+
private string Capture(bool muteExceptions, int attempts, string binary, params string[] args)
119+
{
120+
var lines = CaptureMultiple(muteExceptions, attempts, binary, args);
121+
return lines.FirstOrDefault() ??
122+
(muteExceptions ? string.Empty : throw new Exception($"[{binary} {string.Join(" ", args)}] No output captured executing in : {workingDirectory}"));
127123
}
128124
}

‎src/authoring/Elastic.Documentation.Refactor/Tracking/LocalChangesService.cs‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -46,7 +46,9 @@ public Task<bool> ValidateRedirects(IDiagnosticsCollector collector, string? pat
4646
}
4747
var relativePath = Path.GetRelativePath(root.FullName, buildContext.DocumentationSourceDirectory.FullName);
4848
_logger.LogInformation("Using relative path {RelativePath} for validating changes", relativePath);
49-
IRepositoryTracker tracker = runningOnCi ? new IntegrationGitRepositoryTracker(relativePath) : new LocalGitRepositoryTracker(collector, root, relativePath);
49+
IRepositoryTracker tracker = runningOnCi
50+
? new IntegrationGitRepositoryTracker(relativePath)
51+
: new LocalGitRepositoryTracker(logFactory, collector, root, relativePath);
5052
var changed = tracker.GetChangedFiles()
5153
.Where(c =>
5254
{

‎src/authoring/Elastic.Documentation.Refactor/Tracking/LocalGitRepositoryTracker.cs‎

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -5,11 +5,16 @@
55
using System.IO.Abstractions;
66
using Elastic.Documentation.Diagnostics;
77
using Elastic.Documentation.ExternalCommands;
8+
using Microsoft.Extensions.Logging;
89

910
namespace Elastic.Documentation.Refactor.Tracking;
1011

11-
public class LocalGitRepositoryTracker(IDiagnosticsCollector collector, IDirectoryInfo workingDirectory, string lookupPath) : ExternalCommandExecutor(collector, workingDirectory), IRepositoryTracker
12+
public class LocalGitRepositoryTracker(ILoggerFactory logFactory, IDiagnosticsCollector collector, IDirectoryInfo workingDirectory, string lookupPath)
13+
: ExternalCommandExecutor(collector, workingDirectory), IRepositoryTracker
1214
{
15+
/// <inheritdoc />
16+
protected override ILogger Logger { get; } = logFactory.CreateLogger<LocalGitRepositoryTracker>();
17+
1318
private string LookupPath { get; } = lookupPath.Trim('\\', '/');
1419

1520
public IReadOnlyCollection<GitChange> GetChangedFiles()
@@ -30,9 +35,9 @@ public IReadOnlyCollection<GitChange> GetChangedFiles()
3035

3136
private string GetDefaultBranch()
3237
{
33-
if (!Capture(true, "git", "merge-base", "-a", "HEAD", "main").StartsWith("fatal", StringComparison.InvariantCulture))
38+
if (!CaptureQuiet("git", "merge-base", "-a", "HEAD", "main").StartsWith("fatal", StringComparison.InvariantCulture))
3439
return "main";
35-
if (!Capture(true, "git", "merge-base", "-a", "HEAD", "master").StartsWith("fatal", StringComparison.InvariantCulture))
40+
if (!CaptureQuiet("git", "merge-base", "-a", "HEAD", "master").StartsWith("fatal", StringComparison.InvariantCulture))
3641
return "master";
3742
return Capture("git", "symbolic-ref", "refs/remotes/origin/HEAD").Split('/').Last();
3843
}

‎src/services/Elastic.Documentation.Assembler/Deploying/Redirects/AwsCloudFrontKeyValueStoreProxy.cs‎

Lines changed: 7 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,8 @@ internal enum KvsOperation
1919
public class AwsCloudFrontKeyValueStoreProxy(IDiagnosticsCollector collector, ILoggerFactory logFactory, IDirectoryInfo workingDirectory)
2020
: ExternalCommandExecutor(collector, workingDirectory)
2121
{
22-
private readonly ILogger _logger = logFactory.CreateLogger<AwsCloudFrontKeyValueStoreProxy>();
22+
/// <inheritdoc />
23+
protected override ILogger Logger { get; } = logFactory.CreateLogger<AwsCloudFrontKeyValueStoreProxy>();
2324

2425
public void UpdateRedirects(string kvsName, IReadOnlyDictionary<string, string> sourcedRedirects)
2526
{
@@ -50,7 +51,7 @@ public void UpdateRedirects(string kvsName, IReadOnlyDictionary<string, string>
5051

5152
private string DescribeKeyValueStore(string kvsName)
5253
{
53-
_logger.LogInformation("Describing KeyValueStore");
54+
Logger.LogInformation("Describing KeyValueStore");
5455
try
5556
{
5657
var json = CaptureMultiple("aws", "cloudfront", "describe-key-value-store", "--name", kvsName);
@@ -77,7 +78,7 @@ private string DescribeKeyValueStore(string kvsName)
7778

7879
private string AcquireETag(string kvsArn)
7980
{
80-
_logger.LogInformation("Acquiring ETag for updates");
81+
Logger.LogInformation("Acquiring ETag for updates");
8182
try
8283
{
8384
var json = CaptureMultiple("aws", "cloudfront-keyvaluestore", "describe-key-value-store", "--kvs-arn", kvsArn);
@@ -103,7 +104,7 @@ private string AcquireETag(string kvsArn)
103104

104105
private bool TryListAllKeys(string kvsArn, out HashSet<string> keys)
105106
{
106-
_logger.LogInformation("Acquiring existing redirects");
107+
Logger.LogInformation("Acquiring existing redirects");
107108
keys = [];
108109
string[] baseArgs = ["cloudfront-keyvaluestore", "list-keys", "--kvs-arn", kvsArn, "--page-size", "50", "--max-items", "50"];
109110
string? nextToken = null;
@@ -145,7 +146,7 @@ private string ProcessBatchUpdates(
145146
KvsOperation operation)
146147
{
147148
const int batchSize = 50;
148-
_logger.LogInformation("Processing {Count} items in batches of {BatchSize} for {Operation} update operation.", items.Count, batchSize, operation);
149+
Logger.LogInformation("Processing {Count} items in batches of {BatchSize} for {Operation} update operation.", items.Count, batchSize, operation);
149150
try
150151
{
151152
foreach (var batch in items.Chunk(batchSize))
@@ -158,7 +159,7 @@ private string ProcessBatchUpdates(
158159
AwsCloudFrontKeyValueStoreJsonContext.Default.ListDeleteKeyRequestListItem),
159160
_ => string.Empty
160161
};
161-
var responseJson = CaptureMultiple(false, 1, "aws", "cloudfront-keyvaluestore", "update-keys", "--kvs-arn", kvsArn, "--if-match", eTag,
162+
var responseJson = CaptureMultiple(1, "aws", "cloudfront-keyvaluestore", "update-keys", "--kvs-arn", kvsArn, "--if-match", eTag,
162163
$"--{operation.ToString().ToLowerInvariant()}", payload);
163164

164165
var concatJson = string.Concat(responseJson);

‎src/services/Elastic.Documentation.Assembler/Sourcing/GitFacade.cs‎

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
using System.IO.Abstractions;
66
using Elastic.Documentation.Diagnostics;
77
using Elastic.Documentation.ExternalCommands;
8+
using Microsoft.Extensions.Logging;
89

910
namespace Elastic.Documentation.Assembler.Sourcing;
1011

@@ -23,8 +24,13 @@ public interface IGitRepository
2324

2425
// This git repository implementation is optimized for pull and fetching single commits.
2526
// It uses `git pull --depth 1` and `git fetch --depth 1` to minimize the amount of data transferred.
26-
public class SingleCommitOptimizedGitRepository(IDiagnosticsCollector collector, IDirectoryInfo workingDirectory) : ExternalCommandExecutor(collector, workingDirectory), IGitRepository
27+
public class SingleCommitOptimizedGitRepository(ILoggerFactory logFactory, IDiagnosticsCollector collector, IDirectoryInfo workingDirectory)
28+
: ExternalCommandExecutor(collector, workingDirectory, Environment.GetEnvironmentVariable("CI") is null or "" ? null : TimeSpan.FromMinutes(10))
29+
, IGitRepository
2730
{
31+
/// <inheritdoc />
32+
protected override ILogger Logger { get; } = logFactory.CreateLogger<SingleCommitOptimizedGitRepository>();
33+
2834
private static readonly Dictionary<string, string> EnvironmentVars = new()
2935
{
3036
// Disable git editor prompts:

‎src/services/Elastic.Documentation.Assembler/Sourcing/RepositorySourcesFetcher.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -42,7 +42,7 @@ public CheckoutResult GetAll()
4242
_logger.LogInformation("{RepositoryName}: Using local override path for {RepositoryName} at {Path}", repo.Name, repo.Name, repo.Path);
4343
checkoutFolder = fs.DirectoryInfo.New(repo.Path);
4444
}
45-
IGitRepository gitFacade = new SingleCommitOptimizedGitRepository(context.Collector, checkoutFolder);
45+
IGitRepository gitFacade = new SingleCommitOptimizedGitRepository(logFactory, context.Collector, checkoutFolder);
4646
if (!checkoutFolder.Exists)
4747
{
4848
context.Collector.EmitError(checkoutFolder.FullName, $"'{repo.Name}' does not exist in link index checkout directory");
@@ -156,7 +156,7 @@ public Checkout CloneRef(Repository repository, string gitRef, bool pull = false
156156
_logger.LogInformation("{RepositoryName}: Using override path for {RepositoryName}@{Commit} at {CheckoutFolder}", repository.Name, repository.Name, gitRef, checkoutFolder.FullName);
157157
}
158158

159-
IGitRepository git = new SingleCommitOptimizedGitRepository(collector, checkoutFolder);
159+
IGitRepository git = new SingleCommitOptimizedGitRepository(logFactory, collector, checkoutFolder);
160160

161161
if (assumeCloned && checkoutFolder.Exists)
162162
{

0 commit comments

Comments
 (0)