Skip to content

Commit

Permalink
Add reference docs link to InboundHandler warning (elastic#109203)
Browse files Browse the repository at this point in the history
Seems like it would be useful to link to the relevant docs here.
  • Loading branch information
DaveCTurner authored May 30, 2024
1 parent 56dd538 commit d26be67
Show file tree
Hide file tree
Showing 5 changed files with 32 additions and 23 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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
;

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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"
}
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand All @@ -285,21 +290,24 @@ 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);
// expect no response - channel just closed on 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();
Expand All @@ -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(), () -> {}));
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2187,6 +2187,10 @@ public static <T> T safeGet(Future<T> future) {
}
}

public static void safeSleep(TimeValue timeValue) {
safeSleep(timeValue.millis());
}

public static void safeSleep(long millis) {
try {
Thread.sleep(millis);
Expand Down

0 comments on commit d26be67

Please sign in to comment.