From f468cc87a143addee2b535df4be9e439511928e4 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Thu, 11 Sep 2025 10:52:38 +1000 Subject: [PATCH 1/7] log the timeout ms Signed-off-by: Sally MacFarlane --- .../ethereum/api/handlers/JsonRpcExecutorHandler.java | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java index fb95f817862..9a3e179c3d0 100644 --- a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java +++ b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java @@ -40,14 +40,18 @@ public static Handler handler( final Tracer tracer, final JsonRpcConfiguration jsonRpcConfiguration) { return ctx -> { + long timeoutMillis = jsonRpcConfiguration.getHttpTimeoutSec() * 1000; final long timerId = ctx.vertx() .setTimer( - jsonRpcConfiguration.getHttpTimeoutSec() * 1000, + timeoutMillis, id -> { final String method = ctx.get(ContextKey.REQUEST_BODY_AS_JSON_OBJECT.name()).toString(); - LOG.error("Timeout occurred in JSON-RPC executor for method {}", method); + LOG.error( + "Timeout ({} ms) occurred in JSON-RPC executor for method {}", + timeoutMillis, + method); handleErrorAndEndResponse(ctx, null, RpcErrorType.TIMEOUT_ERROR); }); From 453b42d3fe2939c83b71b7db62c47fd1e38d6a10 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Thu, 11 Sep 2025 10:52:51 +1000 Subject: [PATCH 2/7] test with non-default value Signed-off-by: Sally MacFarlane --- .../ethereum/api/handlers/JsonRpcExecutorHandlerTest.java | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/ethereum/api/src/test/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandlerTest.java b/ethereum/api/src/test/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandlerTest.java index d002cb34bf0..416cd774ecb 100644 --- a/ethereum/api/src/test/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandlerTest.java +++ b/ethereum/api/src/test/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandlerTest.java @@ -46,6 +46,7 @@ class JsonRpcExecutorHandlerTest { private RoutingContext mockContext; private Vertx mockVertx; private HttpServerResponse mockResponse; + private final long timeoutSeconds = 22; @BeforeEach void setUp() { @@ -56,7 +57,7 @@ void setUp() { mockVertx = mock(Vertx.class); mockResponse = mock(HttpServerResponse.class); - when(mockConfig.getHttpTimeoutSec()).thenReturn(30L); + when(mockConfig.getHttpTimeoutSec()).thenReturn(timeoutSeconds); when(mockContext.vertx()).thenReturn(mockVertx); when(mockContext.response()).thenReturn(mockResponse); when(mockResponse.ended()).thenReturn(false); @@ -80,7 +81,8 @@ void testTimeoutHandling() { handler.handle(mockContext); // Assert - verify(mockVertx).setTimer(eq(30000L), any()); + long timeoutMillis = timeoutSeconds * 1000; + verify(mockVertx).setTimer(eq(timeoutMillis), any()); // Simulate timeout timerHandlerCaptor.getValue().handle(1L); From 891a1067c8dbf941af85e8958cedc2975d0438b3 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Thu, 11 Sep 2025 13:25:54 +1000 Subject: [PATCH 3/7] log rpc config at startup Signed-off-by: Sally MacFarlane --- app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java | 2 ++ .../org/hyperledger/besu/cli/options/GraphQlOptions.java | 6 +++--- .../hyperledger/besu/cli/options/JsonRpcHttpOptions.java | 6 +++--- .../hyperledger/besu/cli/options/RpcWebsocketOptions.java | 6 +++--- 4 files changed, 11 insertions(+), 9 deletions(-) diff --git a/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java b/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java index 7f574b366f3..36572738fdb 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java +++ b/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java @@ -1678,8 +1678,10 @@ private void configure() throws Exception { jsonRpcConfiguration = jsonRpcHttpOptions.jsonRpcConfiguration( hostsAllowlist, p2PDiscoveryOptions.p2pHost, unstableRPCOptions.getHttpTimeoutSec()); + logger.info("RPC HTTP JSON-RPC config: {}", jsonRpcConfiguration); if (isEngineApiEnabled()) { engineJsonRpcConfiguration = createEngineJsonRpcConfiguration(); + logger.info("Engine JSON-RPC config: {}", engineJsonRpcConfiguration); // align JSON decoding limit with HTTP body limit // character count is close to size in bytes final long maxRequestContentLength = diff --git a/app/src/main/java/org/hyperledger/besu/cli/options/GraphQlOptions.java b/app/src/main/java/org/hyperledger/besu/cli/options/GraphQlOptions.java index e72e6c23d39..2167507d60a 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/options/GraphQlOptions.java +++ b/app/src/main/java/org/hyperledger/besu/cli/options/GraphQlOptions.java @@ -131,11 +131,11 @@ public void validate(final Logger logger, final CommandLine commandLine) { * * @param hostsAllowlist List of hosts allowed * @param defaultHostAddress Default host address - * @param timoutSec Timeout in seconds + * @param timeoutSec Timeout in seconds * @return A GraphQLConfiguration instance */ public GraphQLConfiguration graphQLConfiguration( - final List hostsAllowlist, final String defaultHostAddress, final Long timoutSec) { + final List hostsAllowlist, final String defaultHostAddress, final Long timeoutSec) { final GraphQLConfiguration graphQLConfiguration = GraphQLConfiguration.createDefault(); graphQLConfiguration.setEnabled(isGraphQLHttpEnabled); graphQLConfiguration.setHost( @@ -143,7 +143,7 @@ public GraphQLConfiguration graphQLConfiguration( graphQLConfiguration.setPort(graphQLHttpPort); graphQLConfiguration.setHostsAllowlist(hostsAllowlist); graphQLConfiguration.setCorsAllowedDomains(graphQLHttpCorsAllowedOrigins); - graphQLConfiguration.setHttpTimeoutSec(timoutSec); + graphQLConfiguration.setHttpTimeoutSec(timeoutSec); graphQLConfiguration.setTlsEnabled(graphqlTlsEnabled); graphQLConfiguration.setTlsKeyStorePath(graphqlTlsKeystoreFile); graphQLConfiguration.setTlsKeyStorePasswordFile(graphqlTlsKeystorePasswordFile); diff --git a/app/src/main/java/org/hyperledger/besu/cli/options/JsonRpcHttpOptions.java b/app/src/main/java/org/hyperledger/besu/cli/options/JsonRpcHttpOptions.java index 371f855b7a0..bf131dce5c1 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/options/JsonRpcHttpOptions.java +++ b/app/src/main/java/org/hyperledger/besu/cli/options/JsonRpcHttpOptions.java @@ -309,18 +309,18 @@ public JsonRpcConfiguration jsonRpcConfiguration() { * * @param hostsAllowlist List of hosts allowed * @param defaultHostAddress Default host address - * @param timoutSec timeout in seconds + * @param timeoutSec timeout in seconds * @return A JsonRpcConfiguration instance */ public JsonRpcConfiguration jsonRpcConfiguration( - final List hostsAllowlist, final String defaultHostAddress, final Long timoutSec) { + final List hostsAllowlist, final String defaultHostAddress, final Long timeoutSec) { final JsonRpcConfiguration jsonRpcConfiguration = this.jsonRpcConfiguration(); jsonRpcConfiguration.setHost( Strings.isNullOrEmpty(rpcHttpHost) ? defaultHostAddress : rpcHttpHost); jsonRpcConfiguration.setHostsAllowlist(hostsAllowlist); - jsonRpcConfiguration.setHttpTimeoutSec(timoutSec); + jsonRpcConfiguration.setHttpTimeoutSec(timeoutSec); return jsonRpcConfiguration; } diff --git a/app/src/main/java/org/hyperledger/besu/cli/options/RpcWebsocketOptions.java b/app/src/main/java/org/hyperledger/besu/cli/options/RpcWebsocketOptions.java index fb7c73e7eae..6106371aa08 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/options/RpcWebsocketOptions.java +++ b/app/src/main/java/org/hyperledger/besu/cli/options/RpcWebsocketOptions.java @@ -343,11 +343,11 @@ private void checkOptionDependencies(final Logger logger, final CommandLine comm * * @param hostsAllowlist List of allowed hosts * @param defaultHostAddress Default host address - * @param wsTimoutSec WebSocket timeout in seconds + * @param wsTimeoutSec WebSocket timeout in seconds * @return WebSocketConfiguration instance */ public WebSocketConfiguration webSocketConfiguration( - final List hostsAllowlist, final String defaultHostAddress, final Long wsTimoutSec) { + final List hostsAllowlist, final String defaultHostAddress, final Long wsTimeoutSec) { final WebSocketConfiguration webSocketConfiguration = WebSocketConfiguration.createDefault(); webSocketConfiguration.setEnabled(isRpcWsEnabled); webSocketConfiguration.setHost( @@ -363,7 +363,7 @@ public WebSocketConfiguration webSocketConfiguration( webSocketConfiguration.setHostsAllowlist(hostsAllowlist); webSocketConfiguration.setAuthenticationPublicKeyFile(rpcWsAuthenticationPublicKeyFile); webSocketConfiguration.setAuthenticationAlgorithm(rpcWebsocketsAuthenticationAlgorithm); - webSocketConfiguration.setTimeoutSec(wsTimoutSec); + webSocketConfiguration.setTimeoutSec(wsTimeoutSec); webSocketConfiguration.setSslEnabled(isRpcWsSslEnabled); webSocketConfiguration.setKeyStorePath(rpcWsKeyStoreFile); webSocketConfiguration.setKeyStoreType(rpcWsKeyStoreType); From c4a0b8b1849b539a0482cc7d75bfda7e45e2dda1 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Thu, 11 Sep 2025 13:26:18 +1000 Subject: [PATCH 4/7] update deprecated option Signed-off-by: Sally MacFarlane --- config/src/main/resources/profiles/performance.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/config/src/main/resources/profiles/performance.toml b/config/src/main/resources/profiles/performance.toml index 3aa01db7849..a7dae6d310e 100644 --- a/config/src/main/resources/profiles/performance.toml +++ b/config/src/main/resources/profiles/performance.toml @@ -1,2 +1,2 @@ Xplugin-rocksdb-high-spec-enabled=true -Xbonsai-parallel-tx-processing-enabled=true \ No newline at end of file +bonsai-parallel-tx-processing-enabled=true \ No newline at end of file From 12d676a30b3cf9384f88c9728a37ea6f2d3f7cce Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Thu, 11 Sep 2025 15:21:16 +1000 Subject: [PATCH 5/7] http timeout not ws timeout Signed-off-by: Sally MacFarlane --- app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java b/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java index 36572738fdb..7e4d417ea80 100644 --- a/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java +++ b/app/src/main/java/org/hyperledger/besu/cli/BesuCommand.java @@ -1839,7 +1839,7 @@ private JsonRpcConfiguration createEngineJsonRpcConfiguration() { jsonRpcHttpOptions.jsonRpcConfiguration( engineRPCConfig.engineHostsAllowlist(), p2PDiscoveryConfig.p2pHost(), - unstableRPCOptions.getWsTimeoutSec()); + unstableRPCOptions.getHttpTimeoutSec()); engineConfig.setPort(engineRPCConfig.engineRpcPort()); engineConfig.setRpcApis(Arrays.asList("ENGINE", "ETH")); engineConfig.setEnabled(isEngineApiEnabled()); From 2fd8b8a6f4af7922bb8737d6a4e4e321a5c22092 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Fri, 12 Sep 2025 14:01:37 +1000 Subject: [PATCH 6/7] truncate error log Signed-off-by: Sally MacFarlane --- .../api/handlers/JsonRpcExecutorHandler.java | 18 ++++++++++++++---- 1 file changed, 14 insertions(+), 4 deletions(-) diff --git a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java index 9a3e179c3d0..f26d52a3446 100644 --- a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java +++ b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java @@ -46,12 +46,12 @@ public static Handler handler( .setTimer( timeoutMillis, id -> { - final String method = + final String requestBodyAsJson = ctx.get(ContextKey.REQUEST_BODY_AS_JSON_OBJECT.name()).toString(); LOG.error( "Timeout ({} ms) occurred in JSON-RPC executor for method {}", timeoutMillis, - method); + getShortLogString(requestBodyAsJson)); handleErrorAndEndResponse(ctx, null, RpcErrorType.TIMEOUT_ERROR); }); @@ -76,14 +76,24 @@ public static Handler handler( cancelTimer(ctx); }); } catch (final RuntimeException e) { - final String method = ctx.get(ContextKey.REQUEST_BODY_AS_JSON_OBJECT.name()).toString(); - LOG.error("Unhandled exception in JSON-RPC executor for method {}", method, e); + final String requestBodyAsJson = + ctx.get(ContextKey.REQUEST_BODY_AS_JSON_OBJECT.name()).toString(); + LOG.error( + "Unhandled exception in JSON-RPC executor for method {}", + getShortLogString(requestBodyAsJson), + e); handleErrorAndEndResponse(ctx, null, RpcErrorType.INTERNAL_ERROR); cancelTimer(ctx); } }; } + private static Object getShortLogString(final String requestBodyAsJson) { + return requestBodyAsJson == null || requestBodyAsJson.length() < 128 + ? requestBodyAsJson + : requestBodyAsJson.substring(0, 128).concat("..."); + } + private static void cancelTimer(final RoutingContext ctx) { Long timerId = ctx.get("timerId"); if (timerId != null) { From e1470319f0ec3cc87ee8980ca9cf8873ca3744f1 Mon Sep 17 00:00:00 2001 From: Sally MacFarlane Date: Fri, 12 Sep 2025 14:29:37 +1000 Subject: [PATCH 7/7] full request in trace log Signed-off-by: Sally MacFarlane --- .../api/handlers/JsonRpcExecutorHandler.java | 20 +++++++++++++++++-- 1 file changed, 18 insertions(+), 2 deletions(-) diff --git a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java index f26d52a3446..84093bd5177 100644 --- a/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java +++ b/ethereum/api/src/main/java/org/hyperledger/besu/ethereum/api/handlers/JsonRpcExecutorHandler.java @@ -52,6 +52,11 @@ public static Handler handler( "Timeout ({} ms) occurred in JSON-RPC executor for method {}", timeoutMillis, getShortLogString(requestBodyAsJson)); + LOG.atTrace() + .setMessage("Timeout ({} ms) occurred in JSON-RPC executor for method {}") + .addArgument(timeoutMillis) + .addArgument(requestBodyAsJson) + .log(); handleErrorAndEndResponse(ctx, null, RpcErrorType.TIMEOUT_ERROR); }); @@ -65,7 +70,13 @@ public static Handler handler( executor.execute(); } catch (IOException e) { final String method = executor.getRpcMethodName(ctx); + final String requestBodyAsJson = + ctx.get(ContextKey.REQUEST_BODY_AS_JSON_OBJECT.name()).toString(); LOG.error("{} - Error streaming JSON-RPC response", method, e); + LOG.atTrace() + .setMessage("{} - Error streaming JSON-RPC response") + .addArgument(requestBodyAsJson) + .log(); handleErrorAndEndResponse(ctx, null, RpcErrorType.INTERNAL_ERROR); } finally { cancelTimer(ctx); @@ -82,6 +93,10 @@ public static Handler handler( "Unhandled exception in JSON-RPC executor for method {}", getShortLogString(requestBodyAsJson), e); + LOG.atTrace() + .setMessage("Unhandled exception in JSON-RPC executor for method {}") + .addArgument(requestBodyAsJson) + .log(); handleErrorAndEndResponse(ctx, null, RpcErrorType.INTERNAL_ERROR); cancelTimer(ctx); } @@ -89,9 +104,10 @@ public static Handler handler( } private static Object getShortLogString(final String requestBodyAsJson) { - return requestBodyAsJson == null || requestBodyAsJson.length() < 128 + final int maxLogLength = 256; + return requestBodyAsJson == null || requestBodyAsJson.length() < maxLogLength ? requestBodyAsJson - : requestBodyAsJson.substring(0, 128).concat("..."); + : requestBodyAsJson.substring(0, maxLogLength).concat("..."); } private static void cancelTimer(final RoutingContext ctx) {