Skip to content

Commit 9ec1eba

Browse files
tippmar-nrtippmar-nr
authored
test: Improve resilience of integration tests (#3656)
1 parent f10d6cc commit 9ec1eba

13 files changed

Lines changed: 135 additions & 26 deletions

File tree

‎tests/Agent/IntegrationTests/IntegrationTestHelpers/AgentLogFile.cs‎

Lines changed: 21 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -64,14 +64,34 @@ public override IEnumerable<string> GetFileLines()
6464
yield break;
6565

6666
string line;
67-
using (var fileStream = new FileStream(FilePath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite))
67+
using (var fileStream = OpenLogFileWithRetry())
6868
using (var streamReader = new StreamReader(fileStream))
6969
while ((line = streamReader.ReadLine()) != null)
7070
{
7171
yield return line;
7272
}
7373
}
7474

75+
// The agent writes to this log concurrently. Even though we open for shared read/write, the
76+
// writer can momentarily hold the file with an incompatible share mode, causing a transient
77+
// IOException on open ("being used by another process"). Retry the open briefly so a read
78+
// that races a write doesn't abort the caller (e.g. WaitForLogLines mid-exercise).
79+
private FileStream OpenLogFileWithRetry()
80+
{
81+
const int maxAttempts = 10;
82+
for (var attempt = 1; ; attempt++)
83+
{
84+
try
85+
{
86+
return new FileStream(FilePath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite);
87+
}
88+
catch (IOException) when (attempt < maxAttempts)
89+
{
90+
Thread.Sleep(100);
91+
}
92+
}
93+
}
94+
7595
public string GetFullLogAsString()
7696
{
7797
using (var fileStream = new FileStream(FilePath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite))

‎tests/Agent/IntegrationTests/IntegrationTestHelpers/RemoteServiceFixtures/RemoteApplicationFixture.cs‎

Lines changed: 31 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -290,21 +290,22 @@ public virtual void Initialize()
290290
var captureStandardOutput = RemoteApplication.CaptureStandardOutput;
291291

292292
var timer = new ExecutionTimer();
293-
timer.Aggregate(() =>
293+
294+
try
294295
{
295-
RemoteApplication.DeleteWorkingSpace();
296+
timer.Aggregate(() =>
297+
{
298+
RemoteApplication.DeleteWorkingSpace();
296299

297-
RemoteApplication.CopyToRemote();
300+
RemoteApplication.CopyToRemote();
298301

299-
SetupConfiguration();
302+
SetupConfiguration();
300303

301-
RemoteApplication.Start(CommandLineArguments, EnvironmentVariables, captureStandardOutput);
302-
});
304+
RemoteApplication.Start(CommandLineArguments, EnvironmentVariables, captureStandardOutput);
305+
});
303306

304-
TestLogger?.WriteLine($"Remote application build/startup time: {timer.Total:N4} seconds");
307+
TestLogger?.WriteLine($"Remote application build/startup time: {timer.Total:N4} seconds");
305308

306-
try
307-
{
308309
timer = new ExecutionTimer();
309310
timer.Aggregate(ExerciseApplication);
310311
TestLogger?.WriteLine($"ExerciseApplication execution time: {timer.Total:N4} seconds");
@@ -334,7 +335,19 @@ public virtual void Initialize()
334335
// hosted tests, unfortunately, we just punt that.
335336
if (RemoteApplication.ValidateHostedWebCoreOutput)
336337
{
337-
SubprocessLogValidator.ValidateHostedWebCoreConsoleOutput(RemoteApplication.CapturedOutput.StandardOutput, TestLogger);
338+
try
339+
{
340+
SubprocessLogValidator.ValidateHostedWebCoreConsoleOutput(RemoteApplication.CapturedOutput.StandardOutput, TestLogger);
341+
}
342+
catch (Exception hwcEx)
343+
{
344+
// If the HWC process hung on shutdown, WaitForOutput() times out and
345+
// StandardOutput is empty, causing spurious "file ended early" failures.
346+
// Convert to a retryable condition instead of an immediate test failure.
347+
TestLogger?.WriteLine($"HostedWebCore log validation failed: {hwcEx.Message}. Will retry if attempts remain.");
348+
retryTest = true;
349+
retryMessage = "HostedWebCore log validation failed.";
350+
}
338351
}
339352
else
340353
{
@@ -346,6 +359,14 @@ public virtual void Initialize()
346359
TestLogger?.WriteLine("Note: child process application does not redirect output because _remoteApplication.CaptureStandardOutput = false. HostedWebCore validation cannot take place without the standard output. This is common for non-web and self-hosted applications.");
347360
}
348361

362+
// If the process is still running (e.g. hung on graceful shutdown), force-kill it
363+
// so that WaitForExit() returns promptly and the port is free for any retry.
364+
if (RemoteApplication.IsRunning)
365+
{
366+
TestLogger?.WriteLine("Remote application is still running after output capture; force killing.");
367+
RemoteApplication.Shutdown(force: true);
368+
}
369+
349370
RemoteApplication.WaitForExit();
350371

351372
applicationHadNonZeroExitCode = RemoteApplication.ExitCode != 0;

‎tests/Agent/IntegrationTests/SharedApplications/Common/MultiFunctionApplicationHelpers/NetStandardLibraries/MySql/MySqlConnectorExerciser.cs‎

Lines changed: 19 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -296,11 +296,25 @@ private void CreateProcedure(string procedureName)
296296
{
297297
var parameters = string.Join(", ", DbParameterData.MySqlParameters.Select(x => $"{x.ParameterName} {x.DbTypeName}"));
298298
var statement = string.Format(CreateProcedureStatement, MySqlTestConfiguration.MySqlDbName, procedureName, parameters);
299-
using (var connection = new MySqlConnection(MySqlTestConfiguration.MySqlConnectionString))
300-
using (var command = new MySqlCommand(statement, connection))
299+
var dropStatement = $"DROP PROCEDURE IF EXISTS `{MySqlTestConfiguration.MySqlDbName}`.`{procedureName}`;";
300+
301+
// Setup-only operation: retry on transient MySQL connection/packet-read faults with a fresh connection.
302+
// DROP IF EXISTS first so a retry is safe even if a prior attempt created the procedure server-side
303+
// before the client lost the response.
304+
MySqlRetryHelper.ExecuteWithRetry(() =>
301305
{
302-
connection.Open();
303-
command.ExecuteNonQuery();
304-
}
306+
using (var connection = new MySqlConnection(MySqlTestConfiguration.MySqlConnectionString))
307+
{
308+
connection.Open();
309+
using (var dropCommand = new MySqlCommand(dropStatement, connection))
310+
{
311+
dropCommand.ExecuteNonQuery();
312+
}
313+
using (var command = new MySqlCommand(statement, connection))
314+
{
315+
command.ExecuteNonQuery();
316+
}
317+
}
318+
});
305319
}
306320
}

‎tests/Agent/IntegrationTests/SharedApplications/Common/MultiFunctionApplicationHelpers/NetStandardLibraries/MySql/MySqlExerciser.cs‎

Lines changed: 19 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -98,11 +98,25 @@ private void CreateProcedure(string procedureName)
9898
{
9999
var parameters = string.Join(", ", DbParameterData.MySqlParameters.Select(x => $"{x.ParameterName} {x.DbTypeName}"));
100100
var statement = string.Format(CreateProcedureStatement, MySqlTestConfiguration.MySqlDbName, procedureName, parameters);
101-
using (var connection = new MySqlConnection(MySqlTestConfiguration.MySqlConnectionString))
102-
using (var command = new MySqlCommand(statement, connection))
101+
var dropStatement = $"DROP PROCEDURE IF EXISTS `{MySqlTestConfiguration.MySqlDbName}`.`{procedureName}`;";
102+
103+
// Setup-only operation: retry on transient MySQL connection/packet-read faults with a fresh connection.
104+
// DROP IF EXISTS first so a retry is safe even if a prior attempt created the procedure server-side
105+
// before the client lost the response.
106+
MySqlRetryHelper.ExecuteWithRetry(() =>
103107
{
104-
connection.Open();
105-
command.ExecuteNonQuery();
106-
}
108+
using (var connection = new MySqlConnection(MySqlTestConfiguration.MySqlConnectionString))
109+
{
110+
connection.Open();
111+
using (var dropCommand = new MySqlCommand(dropStatement, connection))
112+
{
113+
dropCommand.ExecuteNonQuery();
114+
}
115+
using (var command = new MySqlCommand(statement, connection))
116+
{
117+
command.ExecuteNonQuery();
118+
}
119+
}
120+
});
107121
}
108122
}

‎tests/Agent/IntegrationTests/SharedApplications/Common/MultiFunctionApplicationHelpers/NetStandardLibraries/MySql/MySqlRetryHelper.cs‎

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,37 @@
1+
// Copyright 2020 New Relic, Inc. All rights reserved.
2+
// SPDX-License-Identifier: Apache-2.0
3+
4+
using System;
5+
using System.Threading;
6+
7+
namespace MultiFunctionApplicationHelpers.NetStandardLibraries.MySql;
8+
9+
// Small retry helper for MySQL test setup operations. MySQL in the unbounded
10+
// test environment occasionally throws transient connection / packet-read
11+
// faults mid-stream; retrying the setup with a fresh connection avoids flaky
12+
// failures. Only use this for setup (e.g. CreateProcedure), never for the
13+
// instrumented calls that tests assert metric call counts on.
14+
public static class MySqlRetryHelper
15+
{
16+
public static void ExecuteWithRetry(Action action, int maxAttempts = 3, int delayMs = 1000)
17+
{
18+
for (var attempt = 1; ; attempt++)
19+
{
20+
try
21+
{
22+
action();
23+
return;
24+
}
25+
catch (Exception ex)
26+
{
27+
if (attempt >= maxAttempts)
28+
{
29+
throw;
30+
}
31+
32+
ConsoleMFLogger.Info($"MySqlRetryHelper: attempt {attempt} of {maxAttempts} failed with '{ex.Message}'. Retrying in {delayMs}ms.");
33+
Thread.Sleep(delayMs);
34+
}
35+
}
36+
}
37+
}

‎tests/Agent/IntegrationTests/UnboundedIntegrationTests/Couchbase/Couchbase2Tests.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -61,7 +61,7 @@ protected Couchbase2TestsBase(TFixture fixture, ITestOutputHelper output) : base
6161

6262
configModifier.SetLogLevel("finest");
6363

64-
configModifier.ConfigureFasterMetricsHarvestCycle(30);
64+
configModifier.ConfigureFasterMetricsHarvestCycle(10);
6565
configModifier.ConfigureFasterSpanEventsHarvestCycle(10);
6666
configModifier.ConfigureFasterSqlTracesHarvestCycle(10);
6767
configModifier.ConfigureFasterTransactionTracesHarvestCycle(10);

‎tests/Agent/IntegrationTests/UnboundedIntegrationTests/Couchbase/Couchbase3Tests.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -108,7 +108,7 @@ protected Couchbase3TestsBase(TFixture fixture, ITestOutputHelper output) : base
108108

109109
configModifier.SetLogLevel("finest");
110110

111-
configModifier.ConfigureFasterMetricsHarvestCycle(30);
111+
configModifier.ConfigureFasterMetricsHarvestCycle(10);
112112
configModifier.ConfigureFasterSpanEventsHarvestCycle(10);
113113
configModifier.ConfigureFasterSqlTracesHarvestCycle(10);
114114
configModifier.ConfigureFasterTransactionTracesHarvestCycle(10);

‎tests/Agent/IntegrationTests/UnboundedIntegrationTests/MsSql/MsSqlTruncationTests.cs‎

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -25,10 +25,7 @@ public MsSqlTruncationTestsBase(TFixture fixture, ITestOutputHelper output, stri
2525
_fixture = fixture;
2626
_fixture.TestLogger = output;
2727

28-
_fixture.BaselinePayloadBytes = 61446; // Baseline payload size for Core Latest agent with Microsoft.Data.SqlClient
29-
3028
_fixture.AddCommand($"{exerciserName} MsSqlWithLongQuery");
31-
_fixture.AddCommand($"{exerciserName} Wait 5000");
3229

3330
_fixture.AddActions
3431
(

‎tests/Agent/IntegrationTests/UnboundedIntegrationTests/MySql/MySqlAsyncTests.cs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -50,6 +50,7 @@ public MySqlAsyncTestsBase(TFixture fixture, ITestOutputHelper output) : base(fi
5050
// Confirm transaction transform has completed before moving on to host application shutdown, and final sendDataOnExit harvest
5151
_fixture.AgentLog.WaitForLogLine(AgentLogBase.TransactionTransformCompletedLogLineRegex, TimeSpan.FromMinutes(2)); // must be 2 minutes since this can take a while.
5252
_fixture.AgentLog.WaitForLogLine(AgentLogBase.SqlTraceDataLogLineRegex, TimeSpan.FromMinutes(1));
53+
_fixture.AgentLog.WaitForLogLine(AgentLogBase.TransactionSampleLogLineRegex, TimeSpan.FromMinutes(1));
5354
_fixture.AgentLog.WaitForLogLine(AgentLogBase.AnalyticsEventDataLogLineRegex, TimeSpan.FromMinutes(1));
5455
}
5556
);

‎tests/Agent/IntegrationTests/UnboundedIntegrationTests/MySql/MySqlConnectorTests.cs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -75,6 +75,7 @@ protected MySqlConnectorTestBase(TFixture fixture, ITestOutputHelper output) : b
7575
// Confirm transaction transform has completed before moving on to host application shutdown, and final sendDataOnExit harvest
7676
_fixture.AgentLog.WaitForLogLine(AgentLogBase.TransactionTransformCompletedLogLineRegex, TimeSpan.FromMinutes(2));
7777
_fixture.AgentLog.WaitForLogLine(AgentLogBase.SqlTraceDataLogLineRegex, TimeSpan.FromMinutes(1));
78+
_fixture.AgentLog.WaitForLogLine(AgentLogBase.TransactionSampleLogLineRegex, TimeSpan.FromMinutes(1));
7879
_fixture.AgentLog.WaitForLogLine(AgentLogBase.AnalyticsEventDataLogLineRegex, TimeSpan.FromMinutes(1));
7980
}
8081
);

0 commit comments

Comments
 (0)