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.

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

suggested tweaks to observability setup #475

Merged
merged 4 commits into from
Jan 29, 2024
Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
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
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

This is why we had a count of 2 after executing a job once. Spring already connects the ObservationRegistry to the MeterRegistry. But here, we were connecting it a second time … and thus, we were recording each observation twice.

Copy link
Contributor

Choose a reason for hiding this comment

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

Dang, introducing this config was my suggestion...I didn't realize Spring was already providing this exact thing out of the box.

I think this perhaps remains a valuable reference snippet for how we might want to customize the observation config when we have a reason to do so, so I wanted to ask to check my own comprehension:

If we just leave the Config class in place and only delete line 23 (.observationHandler(...)), would it have the same/desired effect as dropping the whole file? I imagine wanting to re-introduce this class at some point for the purpose of overriding config, but don't want to cause a regression.

Copy link
Contributor

Choose a reason for hiding this comment

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

tricky!

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

@jladieu my $.02 would be to look back at this PR, or the PR that introduced this code, if we need a reference in the future instead of keeping it in the runtime codebase but doing nothing. That said, yeah, I think just removing the .observationHandler(...) line would have the same effect.

This file was deleted.

Original file line number Diff line number Diff line change
@@ -1,8 +1,11 @@
package org.databiosphere.workspacedataservice.jobexec;

import static org.assertj.core.api.Assertions.assertThat;
import static org.databiosphere.workspacedataservice.shared.model.Schedulable.ARG_TOKEN;
import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.junit.jupiter.api.Assertions.assertNotEquals;
import static org.junit.jupiter.api.Assertions.assertInstanceOf;
import static org.junit.jupiter.api.Assertions.assertNotNull;
import static org.junit.jupiter.api.Assertions.assertNull;
import static org.junit.jupiter.api.Assertions.assertTrue;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.anyString;
Expand All @@ -25,8 +28,8 @@
import org.databiosphere.workspacedataservice.dao.JobDao;
import org.databiosphere.workspacedataservice.generated.GenericJobServerModel;
import org.databiosphere.workspacedataservice.sam.TokenContextUtil;
import org.junit.jupiter.api.AfterAll;
import org.junit.jupiter.api.BeforeAll;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.TestInstance;
import org.quartz.JobDataMap;
Expand All @@ -36,16 +39,27 @@
import org.quartz.impl.JobDetailImpl;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.boot.test.context.TestConfiguration;
import org.springframework.boot.test.mock.mockito.MockBean;
import org.springframework.context.annotation.Bean;

@SpringBootTest
@TestInstance(TestInstance.Lifecycle.PER_CLASS)
class QuartzJobTest {

@MockBean JobDao jobDao;
@Autowired ObservationRegistry observationRegistry;
@Autowired MeterRegistry meterRegistry;
private TestObservationRegistry testObservationRegistry;

@Autowired private ObservationRegistry observationRegistry;

// override Spring's standard ObservationRegistry with a TestObservationRegistry
@TestConfiguration
static class TestObservationConfig {
Copy link
Contributor

Choose a reason for hiding this comment

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

Would you consider making this config universal for all tests? If that's possible, it might be nice to provide an accessor method for the global TestObservationRegistry that tests can use instead of having to @Autowire ObservationRegistry and typecast anywhere that's needed. The typecasting feels clumsy and it'd be nice if it wasn't necessary.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Unfortunately making this config universal for all tests isn't super easy. I've moved the static inner class to a reusable standalone class … but it still requires any test that needs it to include it via @Import and to perform the appropriate casting.

fwiw, I kinda like the inclusion of

    // this test requires a TestObservationRegistry
    TestObservationRegistry testObservationRegistry =
        assertInstanceOf(TestObservationRegistry.class, observationRegistry);

in the unit test, as it ensures the unit test is set up correctly.

@Bean
ObservationRegistry testObservationRegistry() {
return TestObservationRegistry.create();
}
}
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

This replaces the default ObservationRegistry bean with a TestObservationRegistry inside this test, instead of keeping the default ObservationRegistry bean and adding an additional (non-bean) TestObservationRegistry.


@BeforeAll
void beforeAll() {
Expand All @@ -64,16 +78,14 @@ void beforeAll() {
.thenThrow(new RuntimeException("test failed via jobDao.fail()"));
when(jobDao.fail(any(), anyString()))
.thenThrow(new RuntimeException("test failed via jobDao.fail()"));
// set up metrics registries
testObservationRegistry = TestObservationRegistry.create();
Metrics.globalRegistry.add(meterRegistry);
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

this setup is not necessary; Spring handles it for us once we make TestObservationRegistry a Spring-managed bean.

Copy link
Contributor

Choose a reason for hiding this comment

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

I'm glad that creating a TestObservationRegistry bean does get Metrics to work (it didn't in my implementation, hence why I had to create a test and a regular observation registry)

}

@AfterAll
void afterAll() {
testObservationRegistry.clear();
/** clear all observations and metrics prior to each test */
@BeforeEach
void beforeEach() {
meterRegistry.clear();
Metrics.globalRegistry.clear();
((TestObservationRegistry) observationRegistry).clear();
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

previously, this cleared everything after all tests had run. There's no point to that, as Spring will destroy the context after the whole test finishes anyway.

Instead, I am now clearing everything before each test; this prevents metrics recorded in one test bleeding into the metrics being read by another test.

Copy link
Contributor

Choose a reason for hiding this comment

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

I tried the beforeeach method on thursday but i think I was missing the TestObservationRegistry bean as the missing piece, thank you

}

/**
Expand Down Expand Up @@ -123,6 +135,10 @@ void correctObservation() throws JobExecutionException {
String jobUuid = UUID.randomUUID().toString();
JobExecutionContext mockContext = setUpTestJob(randomToken, jobUuid);

// this test requires a TestObservationRegistry
TestObservationRegistry testObservationRegistry =
assertInstanceOf(TestObservationRegistry.class, observationRegistry);

// execute the TestableQuartzJob, then use testObservationRegistry to confirm observation
new TestableQuartzJob(randomToken, testObservationRegistry).execute(mockContext);

Expand All @@ -142,14 +158,42 @@ void correctMetrics() throws JobExecutionException {
String randomToken = RandomStringUtils.randomAlphanumeric(10);
JobExecutionContext mockContext = setUpTestJob(randomToken, UUID.randomUUID().toString());

// LongTaskTimer and Timer should both be null before we run the job
assertNull(meterRegistry.find("wds.job.execute.active").longTaskTimer());
assertNull(meterRegistry.find("wds.job.execute").timer());

// execute the TestableQuartzJob, then confirm metrics provisioned correctly
new TestableQuartzJob(randomToken, observationRegistry).execute(mockContext);

// metrics provisioned should be longTaskTimer and a Timer, confirm both ran
LongTaskTimer longTaskTimer = meterRegistry.find("wds.job.execute.active").longTaskTimer();
assertNotEquals(0, longTaskTimer.duration(TimeUnit.SECONDS));
assertNotNull(longTaskTimer);
Timer timer = meterRegistry.find("wds.job.execute").timer();
assertNotEquals(0, timer.count());
assertNotNull(timer);

// the LongTaskTimer for wds.job.execute.active tracks "in-flight long-running tasks".
// since the job we just ran is complete, we expect it to show zero active tasks
// and zero duration.
assertEquals(0, longTaskTimer.activeTasks());
assertEquals(0, longTaskTimer.duration(TimeUnit.SECONDS));
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

previously, this test asserted that longTaskTimer.duration was nonzero. The fact it was nonzero seems to be an artifact of recording the same observation twice to the same meterRegistry. Since this is the "*active" metric, it should only be recording currently-in-flight observations, and we should expect it to be zero. Once I cleared up the double-recording, it is now zero.


// the Timer for wds.job.execute tracks history of completed jobs. We expect its duration
// to be nonzero and its count to be 1.
assertThat(timer.totalTime(TimeUnit.SECONDS)).isPositive();
// with one observation, max and total should be the same
assertEquals(timer.totalTime(TimeUnit.SECONDS), timer.max(TimeUnit.SECONDS));
assertEquals(1, timer.count());

// execute the TestableQuartzJob a few more times to further increment the timer count
// and the timer total
double previousTotal = timer.totalTime(TimeUnit.SECONDS);
for (int i = 2; i < 10; i++) {
new TestableQuartzJob(randomToken, observationRegistry).execute(mockContext);
assertEquals(i, timer.count());
// current total should be greater than previous total
assertThat(timer.totalTime(TimeUnit.SECONDS)).isGreaterThan(previousTotal);
previousTotal = timer.totalTime(TimeUnit.SECONDS);
}
}

// sets up a job and returns the job context
Expand Down
Loading