Add async observability to QuartzJob

[ashanhol]

Added Observability to QuartzJob.execute denoting running, failure, and succeed states. The DefaultMeterObservationHandler gives us a built in Timer, Counter, and LongTaskTimer.

Here's how it reports in Prometheus.

# HELP wds_job_execute_job_failed_total
# TYPE wds_job_execute_job_failed_total counter
wds_job_execute_job_failed_total{jobType="TdrManifestQuartzJob",wds_version="0.2.113-SNAPSHOT",} 1.0
# HELP wds_job_execute_job_running_total
# TYPE wds_job_execute_job_running_total counter
wds_job_execute_job_running_total{jobType="TdrManifestQuartzJob",wds_version="0.2.113-SNAPSHOT",} 1.0
# HELP wds_job_execute_seconds
# TYPE wds_job_execute_seconds summary
wds_job_execute_seconds_count{error="JobExecutionException",jobType="TdrManifestQuartzJob",wds_version="0.2.113-SNAPSHOT",} 1.0
wds_job_execute_seconds_sum{error="JobExecutionException",jobType="TdrManifestQuartzJob",wds_version="0.2.113-SNAPSHOT",} 0.522719647
# HELP wds_job_execute_seconds_max
# TYPE wds_job_execute_seconds_max gauge
wds_job_execute_seconds_max{error="JobExecutionException",jobType="TdrManifestQuartzJob",wds_version="0.2.113-SNAPSHOT",} 0.522719647
# HELP wds_job_execute_active_seconds
# TYPE wds_job_execute_active_seconds summary
wds_job_execute_active_seconds_active_count{wds_version="0.2.113-SNAPSHOT",} 1.0
wds_job_execute_active_seconds_duration_sum{wds_version="0.2.113-SNAPSHOT",} 3.752484771
# HELP wds_job_execute_active_seconds_max
# TYPE wds_job_execute_active_seconds_max gauge
wds_job_execute_active_seconds_max{wds_version="0.2.113-SNAPSHOT",} 3.752493404

---

Reminder:

PRs merged into main will not automatically generate a PR in https://github.com/broadinstitute/terra-helmfile to update the WDS image deployed to kubernetes - this action will need to be triggered manually by running the following github action: https://github.com/DataBiosphere/terra-workspace-data-service/actions/workflows/tag.yml. Dont forget to provide a Jira Id when triggering the manual action, if no Jira ID is provided the action will not fully succeed.

After you manually trigger the github action (and it completes with no errors), you must go to the terra-helmfile repo and verify that this generated a PR that merged successfully.

The terra-helmfile PR merge will then generate a PR in leonardo. This will automerge if all tests pass, but if jenkins tests fail it will not; be sure to watch it to ensure it merges. To trigger jenkins retest simply comment on PR with "jenkins retest".

[jladieu]

I have a few comments/suggestions but nothing showstopper. LGTM with pre-emptive approval!

[davidangb]

one question inline, otherwise looking good!

I see this is failing unit tests; it needs some updates for that.

Can you write a test to ensure that QuartzJob is properly recording metrics? If you pass a @MockBean ObservationRegistry observationRegistry (or a @SpyBean), can you verify in the mock/spy that it's doing the right thing?

[jladieu]

@ashanhol I saw your question about whether we might need to customize DefaultMeterObservationHandler and I left some suggestions.

Regarding your question in Slack about whether/how to test this, I think if you merge the PR mentioned here you should be able to adjust QuartzJobTest to use an @Autowired MeterRegistry and then check meters in a test as described in this StackOverflow: https://stackoverflow.com/a/74182551

[davidangb]

comments inline, mostly about tests. Good stuff in this PR!

[davidangb]

How feasible is it to start an Observation in a separate class - and a separate Java thread - and update the Observation here?

We queue the job over in ImportService.java:

terra-workspace-data-service/service/src/main/java/org/databiosphere/workspacedataservice/service/ImportService.java

Line 85 in c6eb725

// schedule the job. after successfully scheduling, mark the job as queued

and if we wanted to track timing between QUEUED and RUNNING status, we'd need to start the Observation over there.

I am totally fine answering this question sometime after this PR merges. What's in this PR as-is is useful and adds value, so it's worth it on its own.

[jladieu]

Good call @davidangb this is actually the spirit behind the measurement, which is to know how long the customer has to wait, so I'm in favor of this. Ok to defer to another PR though if you just want to land this one @ashanhol

[ashanhol]

I actually had this exact thought when doing this, but couldn't quite figure out how to "pass" an observation from one class to another. I'm happy to make a ticket to think about it further.

[ashanhol]

https://broadworkbench.atlassian.net/browse/AJ-1568

[davidangb]

could you add a test for a failing job that looks for .hasLowCardinalityKeyValue("outcome", "failure")? You probably need to modify TestableQuartzJob or create something new that extends QuartzJob but throws an error in executeInternal.

[ashanhol]

OK I'm losing my mind here. In this current test implementation I have the execute function wrapped in a assertThrows, and it fails because it says it doesn't throw anything. But if I get rid of assertThrows it totally does. I feel like I'm missing something obvious

[ashanhol]

OK @jladieu and I figured this out, and it's confusing. We have two JobExecutionExceptions, one from Quartz and one we define. The one we define extends RuntimeException and therefore doesn't need to be caught/handled, but the quartz one does. QuartzJob.execute throws a org.quartz.JobExecutionException (and therefore needs the throws org.quartz.JobExecutionException in the method signature), but all our custom jobs throw various RuntimeException ones. So I had the right idea having the TestQuartzJob throw our custom one but it made writing this test VERY confusing

[davidangb]

Maybe this explanation helps to explain …

The typical data flow is:

• Quartz looks for an execute() method and runs that method when it kicks off a job
• in the WDS codebase, we define the execute() method in QuartzJob.
• QuartzJob.execute() wraps and calls the executeInternal() method defined in subclasses such as TdrManifestQuartzJob or PfbQuartzJob
• As part of its wrapping, QuartzJob.execute() !!catches any exceptions thrown by executeInternal!!. On catch, it marks the job as failed and swallows the exception so Quartz can mark its job as complete.

In this test:

• the test defines a TestableQuartzJob subclass of QuartzJob
• the test throws an exception !!from executeInternal()!!
• the QuartzJob.execute() wrapper properly catches the error thrown from executeInternal(), marks the job as failed, registers metrics, and swallows the error.

So, it's expected that when this test calls TestableQuartzJob(...).execute, it will not throw an error.

[ashanhol]

Yeah, I figured it out eventually. I personally didn't know that RuntimeException had different behavior than regular Exception and that required some compiler fighting and extra confusion with the namespaces.

[davidangb]

Please see #475 for my requested changes to prevent double-counting of metrics!

[davidangb]

one nit/suggestion inline, giving this a proactive 👍

[sonarcloud]

Quality Gate passed

Kudos, no new issues were introduced!

0 New issues
0 Security Hotspots
100.0% Coverage on New Code
0.0% Duplication on New Code

See analysis details on SonarCloud