Skip to content

Commit

Permalink
Only warn when JobFilter is too slow (#961)
Browse files Browse the repository at this point in the history
  • Loading branch information
auloin committed Mar 15, 2024
1 parent 4f4e6fc commit e16fcd0
Show file tree
Hide file tree
Showing 7 changed files with 17 additions and 62 deletions.
2 changes: 1 addition & 1 deletion .idea/compiler.xml

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

2 changes: 1 addition & 1 deletion .idea/misc.xml

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

2 changes: 0 additions & 2 deletions .idea/modules.xml

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

This file was deleted.

This file was deleted.

Original file line number Diff line number Diff line change
Expand Up @@ -10,9 +10,7 @@

import java.util.ArrayList;
import java.util.List;
import java.util.Map;
import java.util.Optional;
import java.util.concurrent.ConcurrentHashMap;
import java.util.function.Consumer;
import java.util.stream.Stream;

Expand All @@ -22,7 +20,6 @@
import static org.jobrunr.utils.reflection.ReflectionUtils.newInstanceCE;

public abstract class AbstractJobFilters {
private static final Map<Class<? extends JobFilter>, Integer> slowJobFilters = new ConcurrentHashMap<>();
protected final AbstractJob job;
private final List<JobFilter> jobFilters;

Expand All @@ -32,7 +29,7 @@ protected AbstractJobFilters(AbstractJob job, JobDefaultFilters jobDefaultFilter
}

protected List<JobFilter> jobFilters() {
return jobFilters.stream().filter(this::isFastJobFilter).collect(toList());
return jobFilters;
}

protected List<JobFilter> initJobFilters(AbstractJob job, List<JobFilter> jobFilters) {
Expand Down Expand Up @@ -118,27 +115,8 @@ final <T extends JobFilter> Consumer<T> catchThrowable(Consumer<T> consumer) {
}

final void logJobFilterTime(JobFilter jobFilter, long durationInNanos) {
Class<? extends JobFilter> jobFilterClass = jobFilter.getClass();
if(NANOSECONDS.toMillis(durationInNanos) > 5) {
slowJobFilters.compute(jobFilterClass, (f, i) -> {
if(i == null || DefaultJobFilter.class.equals(jobFilterClass) || RetryFilter.class.equals(jobFilterClass)) {
return 0;
} else if(i > 3) {
return 5;
} else {
return i + 1;
}
});
} else {
slowJobFilters.put(jobFilterClass, 0);
}
}

private boolean isFastJobFilter(JobFilter jobFilter) {
boolean isSlowJobFilter = slowJobFilters.getOrDefault(jobFilter.getClass(), -1) > 3;
if(isSlowJobFilter) {
if (NANOSECONDS.toMillis(durationInNanos) > 5) {
getLogger().warn("JobFilter of type '{}' is skipped because its slow performance (> 5ms) negatively impacts the overall functioning of JobRunr. JobRunr Pro can run slow running Job Filters without a negative performance impact.", jobFilter.getClass().getName());
}
return !isSlowJobFilter;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -3,24 +3,16 @@
import ch.qos.logback.LoggerAssert;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.Test;

import java.util.Map;

import static java.util.Collections.emptyMap;
import static org.jobrunr.JobRunrAssertions.assertThat;
import static org.jobrunr.jobs.JobTestBuilder.anEnqueuedJob;
import static org.mockito.internal.util.reflection.Whitebox.getInternalState;

class AbstractJobFiltersTest {

@AfterEach
void resetSlowFilters() {
((Map)getInternalState(AbstractJobFilters.class, "slowJobFilters")).clear();
}

@Test
void ifJobFilterIsTooSlowItIsExpelledAndMessageIsLogged() {
void ifJobFilterIsTooSlowAMessageIsLogged() {
MyJobFilter myJobFilter = new MyJobFilter();
JobCreationFilters jobCreationFilters = new JobCreationFilters(anEnqueuedJob().build(), new JobDefaultFilters(myJobFilter));
final ListAppender<ILoggingEvent> logger = LoggerAssert.initFor(jobCreationFilters);
Expand All @@ -31,24 +23,27 @@ void ifJobFilterIsTooSlowItIsExpelledAndMessageIsLogged() {
jobCreationFilters.logJobFilterTime(myJobFilter, 6000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 6000000);

assertThat(jobCreationFilters.jobFilters()).doesNotHaveAnyElementsOfTypes(MyJobFilter.class);
assertThat(logger).hasWarningMessageContaining("JobFilter of type 'org.jobrunr.jobs.filters.AbstractJobFiltersTest$MyJobFilter' is skipped because its slow performance (> 5ms) negatively impacts the overall functioning of JobRunr");
assertThat(logger).hasWarningMessageContaining(
"JobFilter of type 'org.jobrunr.jobs.filters.AbstractJobFiltersTest$MyJobFilter' is skipped because its slow performance (> 5ms) negatively impacts the overall functioning of JobRunr",
5,
emptyMap()
);
}

@Test
void ifJobFilterIsTemporarySlowButThenFastAgainItIsNotExpelled() {
void ifJobFilterIsNotSlowNoMessageIsLogged() {
MyJobFilter myJobFilter = new MyJobFilter();
JobCreationFilters jobCreationFilters = new JobCreationFilters(anEnqueuedJob().build(), new JobDefaultFilters(myJobFilter));
final ListAppender<ILoggingEvent> logger = LoggerAssert.initFor(jobCreationFilters);

jobCreationFilters.logJobFilterTime(myJobFilter, 6000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 6000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 6000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 6000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 1000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 6000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 1000000);
jobCreationFilters.logJobFilterTime(myJobFilter, 1000000);

assertThat(jobCreationFilters.jobFilters())
.hasAtLeastOneElementOfType(MyJobFilter.class);

assertThat(logger).hasNoWarnLogMessages();
}

public static class MyJobFilter implements JobServerFilter {
Expand Down

0 comments on commit e16fcd0

Please sign in to comment.