Skip to content

Fix some sporadically failing tests #3943

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

Merged
merged 5 commits into from
Oct 30, 2024
Merged

Fix some sporadically failing tests #3943

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
c8d4381
Fix sporadically failing test
trask Oct 29, 2024
35c406c
attempt
trask Oct 30, 2024
ac81ef0
disable-gc-tests
trask Oct 30, 2024
ff28098
revert
trask Oct 30, 2024
9b4f0cf
relax condition
trask Oct 30, 2024
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
1 change: 1 addition & 0 deletions ...or/gc-monitor-tests/src/test/java/com/microsoft/gcmonitortests/VariousCollectorsTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@
import org.junit.jupiter.api.condition.EnabledForJreRange;
import org.junit.jupiter.api.condition.EnabledOnOs;

@Disabled // TODO (trask) too flaky since we stopped re-running tests automatically on failure
Copy link
Member Author

@trask trask Oct 30, 2024

Choose a reason for hiding this comment

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

I ran out of time to look into the flaky failures here

I think we should just disable it for now so that it doesn't impact the release, I've created a work item to track it

class VariousCollectorsTest {

@Test
Expand Down
2 changes: 1 addition & 1 deletion agent/instrumentation/micrometer-1.0/build.gradle.kts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,6 @@ dependencies {

tasks {
withType<Test>().configureEach {
jvmArgs("-Dapplicationinsights.internal.micrometer.step.millis=100")
jvmArgs("-Dapplicationinsights.internal.micrometer.step.millis=1000")
Copy link
Member Author

@trask trask Oct 30, 2024

Choose a reason for hiding this comment

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

this was the real fix for the MicrometerTest, I couldn't isolate why though as I was never able to reproduce locally, and the logging I added in CI pointed to some behavior deep in the micrometer internals

}
}
67 changes: 45 additions & 22 deletions agent/instrumentation/micrometer-1.0/src/test/java/MicrometerTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@

import static java.util.concurrent.TimeUnit.MILLISECONDS;
import static org.assertj.core.api.Assertions.assertThat;
import static org.awaitility.Awaitility.await;

import com.microsoft.applicationinsights.agent.bootstrap.MicrometerUtil;
import io.micrometer.core.instrument.Clock;
Expand All @@ -27,8 +28,6 @@

class MicrometerTest {
Copy link
Member Author

@trask trask Oct 30, 2024

Choose a reason for hiding this comment

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

the changes in this class seem worth keeping even though they didn't fix anything


private static final long SLEEP_MILLISECONDS = 6000;

private static final AgentTestingMicrometerDelegate delegate =
new AgentTestingMicrometerDelegate();

Expand Down Expand Up @@ -57,15 +56,14 @@ void shouldNotDoubleRegisterAzureMonitorMeterRegistry() {
}

@Test
void shouldCaptureTimeGauge() throws InterruptedException {
void shouldCaptureTimeGauge() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;
TimeGauge.builder("test-time-gauge", "", MILLISECONDS, obj -> 11.0).register(registry);

// when
Thread.sleep(SLEEP_MILLISECONDS);

// then
await().until(() -> getLastMeasurement("test-time-gauge") != null);

AgentTestingMicrometerDelegate.Measurement measurement = getLastMeasurement("test-time-gauge");
assertThat(measurement.value).isEqualTo(11);
assertThat(measurement.count).isNull();
Expand All @@ -75,15 +73,16 @@ void shouldCaptureTimeGauge() throws InterruptedException {
}

@Test
void shouldCaptureGauge() throws InterruptedException {
void shouldCaptureGauge() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;

// when
Gauge.builder("test-gauge", () -> 22.0).register(registry);
Thread.sleep(SLEEP_MILLISECONDS);

// then
await().until(() -> getLastMeasurement("test-gauge") != null);

AgentTestingMicrometerDelegate.Measurement measurement = getLastMeasurement("test-gauge");
assertThat(measurement.value).isEqualTo(22);
assertThat(measurement.count).isNull();
Expand All @@ -94,16 +93,17 @@ void shouldCaptureGauge() throws InterruptedException {

@Disabled
@Test
void shouldCaptureCounter() throws InterruptedException {
void shouldCaptureCounter() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;

// when
Counter counter = Counter.builder("test-counter").register(registry);
counter.increment(3.3);
Thread.sleep(SLEEP_MILLISECONDS);

// then
await().until(() -> getLastMeasurement("test-counter") != null);

AgentTestingMicrometerDelegate.Measurement measurement = getLastMeasurement("test-counter");
assertThat(measurement.value).isEqualTo(3.3);
assertThat(measurement.count).isNull();
Expand All @@ -113,17 +113,18 @@ void shouldCaptureCounter() throws InterruptedException {
}

@Test
void shouldCaptureTimer() throws InterruptedException {
void shouldCaptureTimer() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;
Timer timer = Timer.builder("test-timer").register(registry);

// when
timer.record(Duration.ofMillis(44));
timer.record(Duration.ofMillis(55));
Thread.sleep(SLEEP_MILLISECONDS);

// then
await().until(() -> getLastMeasurement("test-timer") != null);

AgentTestingMicrometerDelegate.Measurement measurement = getLastMeasurement("test-timer");
assertThat(measurement.value).isEqualTo(99);
assertThat(measurement.count).isEqualTo(2);
Expand All @@ -134,7 +135,7 @@ void shouldCaptureTimer() throws InterruptedException {
}

@Test
void shouldCaptureDistributionSummary() throws InterruptedException {
void shouldCaptureDistributionSummary() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;
DistributionSummary distributionSummary =
Expand All @@ -143,9 +144,10 @@ void shouldCaptureDistributionSummary() throws InterruptedException {
// when
distributionSummary.record(4.4);
distributionSummary.record(5.5);
Thread.sleep(SLEEP_MILLISECONDS);

// then
await().until(() -> getLastMeasurement("test-summary") != null);

AgentTestingMicrometerDelegate.Measurement measurement = getLastMeasurement("test-summary");
assertThat(measurement.value).isEqualTo(9.9);
assertThat(measurement.count).isEqualTo(2);
Expand All @@ -156,7 +158,7 @@ void shouldCaptureDistributionSummary() throws InterruptedException {
}

@Test
void shouldCaptureLongTaskTimer() throws InterruptedException {
void shouldCaptureLongTaskTimer() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;

Expand Down Expand Up @@ -186,9 +188,16 @@ void shouldCaptureLongTaskTimer() throws InterruptedException {
});
});

Thread.sleep(SLEEP_MILLISECONDS);

// then
await()
.untilAsserted(
() -> {
AgentTestingMicrometerDelegate.Measurement activeMeasurement =
getLastMeasurement("test-long-task-timer_active");
assertThat(activeMeasurement).isNotNull();
assertThat(activeMeasurement.value).isEqualTo(2);
});

AgentTestingMicrometerDelegate.Measurement activeMeasurement =
getLastMeasurement("test-long-task-timer_active");
assertThat(activeMeasurement.value).isEqualTo(2);
Expand All @@ -197,6 +206,15 @@ void shouldCaptureLongTaskTimer() throws InterruptedException {
assertThat(activeMeasurement.max).isNull();
assertThat(activeMeasurement.namespace).isNull();

await()
.untilAsserted(
() -> {
AgentTestingMicrometerDelegate.Measurement durationMeasurement =
getLastMeasurement("test-long-task-timer_duration");
assertThat(durationMeasurement).isNotNull();
assertThat(durationMeasurement.value).isGreaterThan(50);
});

AgentTestingMicrometerDelegate.Measurement durationMeasurement =
getLastMeasurement("test-long-task-timer_duration");
assertThat(durationMeasurement.value).isGreaterThan(50);
Expand All @@ -207,15 +225,16 @@ void shouldCaptureLongTaskTimer() throws InterruptedException {
}

@Test
void shouldCaptureFunctionCounter() throws InterruptedException {
void shouldCaptureFunctionCounter() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;

// when
FunctionCounter.builder("test-function-counter", "", obj -> 6.6).register(registry);
Thread.sleep(SLEEP_MILLISECONDS);

// then
await().until(() -> getLastMeasurement("test-function-counter") != null);

AgentTestingMicrometerDelegate.Measurement measurements =
getLastMeasurement("test-function-counter");
assertThat(measurements.value).isEqualTo(6.6);
Expand All @@ -226,16 +245,17 @@ void shouldCaptureFunctionCounter() throws InterruptedException {
}

@Test
void shouldCaptureFunctionTimer() throws InterruptedException {
void shouldCaptureFunctionTimer() {
// given
CompositeMeterRegistry registry = Metrics.globalRegistry;

// when
FunctionTimer.builder("test-function-timer", "", obj -> 2, obj -> 4.4, MILLISECONDS)
.register(registry);
Thread.sleep(SLEEP_MILLISECONDS);

// then
await().until(() -> getLastMeasurement("test-function-timer") != null);

AgentTestingMicrometerDelegate.Measurement measurement =
getLastMeasurement("test-function-timer");
assertThat(measurement.value).isEqualTo(4.4);
Expand All @@ -245,11 +265,14 @@ void shouldCaptureFunctionTimer() throws InterruptedException {
assertThat(measurement.namespace).isNull();
}

public AgentTestingMicrometerDelegate.Measurement getLastMeasurement(String name) {
private static AgentTestingMicrometerDelegate.Measurement getLastMeasurement(String name) {
List<AgentTestingMicrometerDelegate.Measurement> measurements =
delegate.getMeasurements().stream()
.filter(measurement -> measurement.name.equals(name) && measurement.value != 0)
.collect(Collectors.toList());
if (measurements.isEmpty()) {
return null;
}
return measurements.get(measurements.size() - 1);
}
}
2 changes: 1 addition & 1 deletion ...xMetric/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/JmxMetricTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -175,7 +175,7 @@ private void verifyJmxMetricsSentToBreeze() throws Exception {
// versions
if (testing.getCurrentEnvironment() == TOMCAT_8_JAVA_21
|| testing.getCurrentEnvironment() == TOMCAT_8_JAVA_23) {
assertThat(wildcardValueSum).isEqualTo(gcFirstMatch + gcSecondMatch + 6);
assertThat(wildcardValueSum).isGreaterThanOrEqualTo(gcFirstMatch + gcSecondMatch);
Copy link
Member Author

@trask trask Oct 30, 2024

Choose a reason for hiding this comment

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

6 here represents the number of other GC collections, but doesn't appears to be quite a fixed number, so relaxing the condition

} else {
assertThat(wildcardValueSum).isEqualTo(gcFirstMatch + gcSecondMatch);
}
Expand Down
Loading