From d26be67b6f3c12548e718cee82da6cbed764c872 Mon Sep 17 00:00:00 2001 From: David Turner Date: Thu, 30 May 2024 13:44:59 +0100 Subject: [PATCH] Add reference docs link to InboundHandler warning (#109203) Seems like it would be useful to link to the relevant docs here. --- .../elasticsearch/common/ReferenceDocs.java | 1 + .../transport/InboundHandler.java | 15 ++++----- .../common/reference-docs-links.json | 3 +- .../transport/InboundHandlerTests.java | 32 +++++++++++-------- .../org/elasticsearch/test/ESTestCase.java | 4 +++ 5 files changed, 32 insertions(+), 23 deletions(-) diff --git a/server/src/main/java/org/elasticsearch/common/ReferenceDocs.java b/server/src/main/java/org/elasticsearch/common/ReferenceDocs.java index 8e370158d166a..2cac6ddb159bc 100644 --- a/server/src/main/java/org/elasticsearch/common/ReferenceDocs.java +++ b/server/src/main/java/org/elasticsearch/common/ReferenceDocs.java @@ -72,6 +72,7 @@ public enum ReferenceDocs { CONTACT_SUPPORT, UNASSIGNED_SHARDS, EXECUTABLE_JNA_TMPDIR, + NETWORK_THREADING_MODEL, // this comment keeps the ';' on the next line so every entry above has a trailing ',' which makes the diff for adding new links cleaner ; diff --git a/server/src/main/java/org/elasticsearch/transport/InboundHandler.java b/server/src/main/java/org/elasticsearch/transport/InboundHandler.java index 79b6daef671af..37cb8931d8cb0 100644 --- a/server/src/main/java/org/elasticsearch/transport/InboundHandler.java +++ b/server/src/main/java/org/elasticsearch/transport/InboundHandler.java @@ -12,6 +12,7 @@ import org.apache.logging.log4j.Logger; import org.apache.lucene.util.BytesRef; import org.elasticsearch.TransportVersion; +import org.elasticsearch.common.ReferenceDocs; import org.elasticsearch.common.io.stream.ByteBufferStreamInput; import org.elasticsearch.common.io.stream.NamedWriteableAwareStreamInput; import org.elasticsearch.common.io.stream.NamedWriteableRegistry; @@ -169,15 +170,13 @@ private TransportResponseHandler findResponseHandler(Header header) { private static void logSlowMessage(InboundMessage message, long took, long logThreshold, TransportResponseHandler responseHandler) { if (message.getHeader().isRequest()) { - logger.warn("handling request [{}] took [{}ms] which is above the warn threshold of [{}ms]", message, took, logThreshold); + logger.warn(""" + handling request [{}] took [{}ms] which is above the warn threshold of [{}ms]; \ + for more information, see {}""", message, took, logThreshold, ReferenceDocs.NETWORK_THREADING_MODEL); } else { - logger.warn( - "handling response [{}] on handler [{}] took [{}ms] which is above the warn threshold of [{}ms]", - message, - responseHandler, - took, - logThreshold - ); + logger.warn(""" + handling response [{}] on handler [{}] took [{}ms] which is above the warn threshold of [{}ms]; \ + for more information, see {}""", message, responseHandler, took, logThreshold, ReferenceDocs.NETWORK_THREADING_MODEL); } } diff --git a/server/src/main/resources/org/elasticsearch/common/reference-docs-links.json b/server/src/main/resources/org/elasticsearch/common/reference-docs-links.json index 503f02b25eb8d..f3e5bd7a375f1 100644 --- a/server/src/main/resources/org/elasticsearch/common/reference-docs-links.json +++ b/server/src/main/resources/org/elasticsearch/common/reference-docs-links.json @@ -32,5 +32,6 @@ "BOOTSTRAP_CHECK_SECURITY_MINIMAL_SETUP": "security-minimal-setup.html", "CONTACT_SUPPORT": "troubleshooting.html#troubleshooting-contact-support", "UNASSIGNED_SHARDS": "red-yellow-cluster-status.html", - "EXECUTABLE_JNA_TMPDIR": "executable-jna-tmpdir.html" + "EXECUTABLE_JNA_TMPDIR": "executable-jna-tmpdir.html", + "NETWORK_THREADING_MODEL": "modules-network.html#modules-network-threading-model" } diff --git a/server/src/test/java/org/elasticsearch/transport/InboundHandlerTests.java b/server/src/test/java/org/elasticsearch/transport/InboundHandlerTests.java index 23f9a7367298f..c9e1a7dbc0cfd 100644 --- a/server/src/test/java/org/elasticsearch/transport/InboundHandlerTests.java +++ b/server/src/test/java/org/elasticsearch/transport/InboundHandlerTests.java @@ -272,7 +272,12 @@ public void testLogsSlowInboundProcessing() throws Exception { final TransportVersion remoteVersion = TransportVersion.current(); mockLog.addExpectation( - new MockLog.SeenEventExpectation("expected slow request", EXPECTED_LOGGER_NAME, Level.WARN, "handling request ") + new MockLog.SeenEventExpectation( + "expected slow request", + EXPECTED_LOGGER_NAME, + Level.WARN, + "handling request*modules-network.html#modules-network-threading-model" + ) ); final long requestId = randomNonNegativeLong(); @@ -285,13 +290,11 @@ public void testLogsSlowInboundProcessing() throws Exception { BytesStreamOutput byteData = new BytesStreamOutput(); TaskId.EMPTY_TASK_ID.writeTo(byteData); TransportVersion.writeVersion(remoteVersion, byteData); - final InboundMessage requestMessage = new InboundMessage(requestHeader, ReleasableBytesReference.wrap(byteData.bytes()), () -> { - try { - TimeUnit.SECONDS.sleep(1L); - } catch (InterruptedException e) { - throw new AssertionError(e); - } - }); + final InboundMessage requestMessage = new InboundMessage( + requestHeader, + ReleasableBytesReference.wrap(byteData.bytes()), + () -> safeSleep(TimeValue.timeValueSeconds(1)) + ); requestHeader.actionName = TransportHandshaker.HANDSHAKE_ACTION_NAME; requestHeader.headers = Tuple.tuple(Map.of(), Map.of()); handler.inboundMessage(channel, requestMessage); @@ -299,7 +302,12 @@ public void testLogsSlowInboundProcessing() throws Exception { mockLog.assertAllExpectationsMatched(); mockLog.addExpectation( - new MockLog.SeenEventExpectation("expected slow response", EXPECTED_LOGGER_NAME, Level.WARN, "handling response ") + new MockLog.SeenEventExpectation( + "expected slow response", + EXPECTED_LOGGER_NAME, + Level.WARN, + "handling response*modules-network.html#modules-network-threading-model" + ) ); final long responseId = randomNonNegativeLong(); @@ -310,11 +318,7 @@ public void testLogsSlowInboundProcessing() throws Exception { @SuppressWarnings("rawtypes") public void onResponseReceived(long requestId, Transport.ResponseContext context) { assertEquals(responseId, requestId); - try { - TimeUnit.SECONDS.sleep(1L); - } catch (InterruptedException e) { - throw new AssertionError(e); - } + safeSleep(TimeValue.timeValueSeconds(1)); } }); handler.inboundMessage(channel, new InboundMessage(responseHeader, ReleasableBytesReference.empty(), () -> {})); diff --git a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java index 14269a8835f57..02be27b92a1eb 100644 --- a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java +++ b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java @@ -2187,6 +2187,10 @@ public static T safeGet(Future future) { } } + public static void safeSleep(TimeValue timeValue) { + safeSleep(timeValue.millis()); + } + public static void safeSleep(long millis) { try { Thread.sleep(millis);