From 9a1bb39c59c2ae1e96f97a444b5a3f3c065d52f7 Mon Sep 17 00:00:00 2001 From: Benjamin Trent <4357155+benwtrent@users.noreply.github.com> Date: Tue, 15 Sep 2020 11:23:10 -0400 Subject: [PATCH 1/4] [ML] fixes testWatchdog test verifying matcher is interrupted on timeout --- .../ml/filestructurefinder/TimeoutChecker.java | 8 ++++++++ .../filestructurefinder/TimeoutCheckerTests.java | 16 +++++++--------- 2 files changed, 15 insertions(+), 9 deletions(-) diff --git a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java index a943e7b7a7349..556e172fa5142 100644 --- a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java +++ b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java @@ -58,10 +58,18 @@ public class TimeoutChecker implements Closeable { * in the case where {@code timeout} is also null. */ public TimeoutChecker(String operation, TimeValue timeout, ScheduledExecutorService scheduler) { + this(operation, timeout, scheduler, null); + } + + // For more reliable matcher signalling testing, registers matcher before scheduling timeout + TimeoutChecker(String operation, TimeValue timeout, ScheduledExecutorService scheduler, Matcher matcher) { this.operation = operation; this.timeout = timeout; this.checkedThread = Thread.currentThread(); timeoutCheckerWatchdog.add(checkedThread, timeout); + if (matcher != null) { + timeoutCheckerWatchdog.register(matcher); + } this.future = (timeout != null) ? scheduler.schedule(this::setTimeoutExceeded, timeout.nanos(), TimeUnit.NANOSECONDS) : null; } diff --git a/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java b/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java index 34c9a047a9958..cae87981b6407 100644 --- a/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java +++ b/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java @@ -16,6 +16,7 @@ import java.util.concurrent.ScheduledExecutorService; import static org.hamcrest.Matchers.equalTo; +import static org.mockito.Mockito.atLeastOnce; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.verify; @@ -59,21 +60,18 @@ public void testCheckTimeoutExceeded() throws Exception { } } - @AwaitsFix(bugUrl = "https://github.com/elastic/elasticsearch/issues/48861") public void testWatchdog() throws Exception { - TimeValue timeout = TimeValue.timeValueMillis(500); - try (TimeoutChecker timeoutChecker = new TimeoutChecker("watchdog test", timeout, scheduler)) { - TimeoutChecker.TimeoutCheckerWatchdog watchdog = (TimeoutChecker.TimeoutCheckerWatchdog) TimeoutChecker.watchdog; - - Matcher matcher = mock(Matcher.class); - TimeoutChecker.watchdog.register(matcher); + TimeValue timeout = TimeValue.timeValueMillis(10); + Matcher matcher = mock(Matcher.class); + try (TimeoutChecker timeoutChecker = new TimeoutChecker("watchdog test", timeout, scheduler, matcher)) { + final TimeoutChecker.TimeoutCheckerWatchdog watchdog = (TimeoutChecker.TimeoutCheckerWatchdog) TimeoutChecker.watchdog; assertThat(watchdog.registry.get(Thread.currentThread()).matchers.size(), equalTo(1)); try { assertBusy(() -> { - verify(matcher).interrupt(); + verify(matcher, atLeastOnce()).interrupt(); }); } finally { - TimeoutChecker.watchdog.unregister(matcher); + watchdog.unregister(matcher); assertThat(watchdog.registry.get(Thread.currentThread()).matchers.size(), equalTo(0)); } } From 59bb8a111b4be96867d977a5d5ba98a0d14ab4d7 Mon Sep 17 00:00:00 2001 From: Benjamin Trent <4357155+benwtrent@users.noreply.github.com> Date: Tue, 15 Sep 2020 12:33:25 -0400 Subject: [PATCH 2/4] calling matcher.interrupt even if action has already timedout --- .../filestructurefinder/TimeoutChecker.java | 23 +++++++++++-------- .../TimeoutCheckerTests.java | 7 +++--- 2 files changed, 17 insertions(+), 13 deletions(-) diff --git a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java index 556e172fa5142..8350db0eb5785 100644 --- a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java +++ b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java @@ -58,18 +58,10 @@ public class TimeoutChecker implements Closeable { * in the case where {@code timeout} is also null. */ public TimeoutChecker(String operation, TimeValue timeout, ScheduledExecutorService scheduler) { - this(operation, timeout, scheduler, null); - } - - // For more reliable matcher signalling testing, registers matcher before scheduling timeout - TimeoutChecker(String operation, TimeValue timeout, ScheduledExecutorService scheduler, Matcher matcher) { this.operation = operation; this.timeout = timeout; this.checkedThread = Thread.currentThread(); timeoutCheckerWatchdog.add(checkedThread, timeout); - if (matcher != null) { - timeoutCheckerWatchdog.register(matcher); - } this.future = (timeout != null) ? scheduler.schedule(this::setTimeoutExceeded, timeout.nanos(), TimeUnit.NANOSECONDS) : null; } @@ -92,7 +84,6 @@ public synchronized void close() { * @throws ElasticsearchTimeoutException If the operation is found to have taken longer than the permitted time. */ public void check(String where) { - if (timeoutExceeded) { throw new ElasticsearchTimeoutException("Aborting " + operation + " during [" + where + "] as it has taken longer than the timeout of [" + timeout + "]"); @@ -109,7 +100,6 @@ public void check(String where) { * @throws ElasticsearchTimeoutException If the operation is found to have taken longer than the permitted time. */ public Map grokCaptures(Grok grok, String text, String where) { - try { return grok.captures(text); } finally { @@ -151,6 +141,9 @@ public void register(Matcher matcher) { boolean wasFalse = value.registered.compareAndSet(false, true); assert wasFalse; value.matchers.add(matcher); + if (value.isTimedOut()) { + matcher.interrupt(); + } } } @@ -177,6 +170,7 @@ void remove(Thread thread) { void interruptLongRunningThreadIfRegistered(Thread thread) { WatchDogEntry value = registry.get(thread); + value.timedOut(); if (value.registered.get()) { for (Matcher matcher : value.matchers) { matcher.interrupt(); @@ -189,12 +183,21 @@ static class WatchDogEntry { final TimeValue timeout; final AtomicBoolean registered; final Collection matchers; + volatile boolean timedOut; WatchDogEntry(TimeValue timeout) { this.timeout = timeout; this.registered = new AtomicBoolean(false); this.matchers = new CopyOnWriteArrayList<>(); } + + private void timedOut() { + timedOut = true; + } + + private boolean isTimedOut() { + return timedOut; + } } } } diff --git a/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java b/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java index cae87981b6407..a83b4a70ca8b7 100644 --- a/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java +++ b/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java @@ -61,10 +61,11 @@ public void testCheckTimeoutExceeded() throws Exception { } public void testWatchdog() throws Exception { - TimeValue timeout = TimeValue.timeValueMillis(10); - Matcher matcher = mock(Matcher.class); - try (TimeoutChecker timeoutChecker = new TimeoutChecker("watchdog test", timeout, scheduler, matcher)) { + final TimeValue timeout = TimeValue.timeValueMillis(randomIntBetween(10, 500)); + try (TimeoutChecker timeoutChecker = new TimeoutChecker("watchdog test", timeout, scheduler)) { final TimeoutChecker.TimeoutCheckerWatchdog watchdog = (TimeoutChecker.TimeoutCheckerWatchdog) TimeoutChecker.watchdog; + Matcher matcher = mock(Matcher.class); + watchdog.register(matcher); assertThat(watchdog.registry.get(Thread.currentThread()).matchers.size(), equalTo(1)); try { assertBusy(() -> { From 0bd06c6a42e2315550b30287a87b4f0459ac1800 Mon Sep 17 00:00:00 2001 From: Benjamin Trent <4357155+benwtrent@users.noreply.github.com> Date: Wed, 16 Sep 2020 07:15:02 -0400 Subject: [PATCH 3/4] addressing pr comment --- .../xpack/ml/filestructurefinder/TimeoutChecker.java | 6 +++--- .../xpack/ml/filestructurefinder/TimeoutCheckerTests.java | 3 +-- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java index 8350db0eb5785..012d815b47dc4 100644 --- a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java +++ b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java @@ -135,7 +135,7 @@ void add(Thread thread, TimeValue timeout) { } @Override - public void register(Matcher matcher) { + synchronized public void register(Matcher matcher) { WatchDogEntry value = registry.get(Thread.currentThread()); if (value != null) { boolean wasFalse = value.registered.compareAndSet(false, true); @@ -168,7 +168,7 @@ void remove(Thread thread) { assert previousValue != null; } - void interruptLongRunningThreadIfRegistered(Thread thread) { + synchronized void interruptLongRunningThreadIfRegistered(Thread thread) { WatchDogEntry value = registry.get(thread); value.timedOut(); if (value.registered.get()) { @@ -183,7 +183,7 @@ static class WatchDogEntry { final TimeValue timeout; final AtomicBoolean registered; final Collection matchers; - volatile boolean timedOut; + boolean timedOut; WatchDogEntry(TimeValue timeout) { this.timeout = timeout; diff --git a/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java b/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java index a83b4a70ca8b7..2666bcc44f5cc 100644 --- a/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java +++ b/x-pack/plugin/ml/src/test/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutCheckerTests.java @@ -16,7 +16,6 @@ import java.util.concurrent.ScheduledExecutorService; import static org.hamcrest.Matchers.equalTo; -import static org.mockito.Mockito.atLeastOnce; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.verify; @@ -69,7 +68,7 @@ public void testWatchdog() throws Exception { assertThat(watchdog.registry.get(Thread.currentThread()).matchers.size(), equalTo(1)); try { assertBusy(() -> { - verify(matcher, atLeastOnce()).interrupt(); + verify(matcher).interrupt(); }); } finally { watchdog.unregister(matcher); From bda7083191fd365e4f1a77d8c1468af2d7f59445 Mon Sep 17 00:00:00 2001 From: Benjamin Trent <4357155+benwtrent@users.noreply.github.com> Date: Wed, 16 Sep 2020 07:16:38 -0400 Subject: [PATCH 4/4] fixing order --- .../xpack/ml/filestructurefinder/TimeoutChecker.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java index 012d815b47dc4..99ce19e3ad110 100644 --- a/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java +++ b/x-pack/plugin/ml/src/main/java/org/elasticsearch/xpack/ml/filestructurefinder/TimeoutChecker.java @@ -135,7 +135,7 @@ void add(Thread thread, TimeValue timeout) { } @Override - synchronized public void register(Matcher matcher) { + public synchronized void register(Matcher matcher) { WatchDogEntry value = registry.get(Thread.currentThread()); if (value != null) { boolean wasFalse = value.registered.compareAndSet(false, true);