From 2a79e83fef140a60d2cdcfb33ade52f1e777399b Mon Sep 17 00:00:00 2001 From: Kharkunov Eugene Date: Sun, 30 Aug 2026 11:29:24 +0300 Subject: [PATCH 1/3] Implement Jetty request event handler --- .../defold/extender/RequestErrorAdvice.java | 84 ++++++ .../jetty/ExtenderJettyErrorHandler.java | 81 ++++++ .../jetty/JettyRequestEventsHandler.java | 38 +++ .../jetty/JettyServerConfiguration.java | 25 ++ server/src/main/resources/application.yml | 5 + .../jetty/JettyErrorHandlingTest.java | 249 ++++++++++++++++++ 6 files changed, 482 insertions(+) create mode 100644 server/src/main/java/com/defold/extender/RequestErrorAdvice.java create mode 100644 server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java create mode 100644 server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java create mode 100644 server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java create mode 100644 server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java diff --git a/server/src/main/java/com/defold/extender/RequestErrorAdvice.java b/server/src/main/java/com/defold/extender/RequestErrorAdvice.java new file mode 100644 index 00000000..97a6b05c --- /dev/null +++ b/server/src/main/java/com/defold/extender/RequestErrorAdvice.java @@ -0,0 +1,84 @@ +package com.defold.extender; + +import java.util.regex.Matcher; +import java.util.regex.Pattern; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.springframework.beans.factory.annotation.Value; +import org.springframework.http.HttpHeaders; +import org.springframework.http.HttpStatus; +import org.springframework.http.MediaType; +import org.springframework.http.ResponseEntity; +import org.springframework.web.bind.annotation.ExceptionHandler; +import org.springframework.web.bind.annotation.RestControllerAdvice; +import org.springframework.web.multipart.MaxUploadSizeExceededException; +import org.springframework.web.multipart.MultipartException; + +import com.defold.extender.log.Markers; + +/** + * Handles uploads that fail while Jetty parses the multipart body. Parsing happens in + * DispatcherServlet.checkMultipart(), i.e. before the request is mapped to a controller method, so + * the @ExceptionHandler methods inside {@link ExtenderController} are never consulted for these + * failures - the request would otherwise end up in Spring's default /error handling, which + * answers with a bare "400 Bad Request" and logs nothing (see defold/extender#590). + */ +@RestControllerAdvice +public class RequestErrorAdvice { + + private static final Logger LOGGER = LoggerFactory.getLogger(RequestErrorAdvice.class); + + // Jetty caps the number of multipart parts at ServletContextHandler.getMaxFormKeys() + // (server.jetty.max-form-keys) and reports it as: Form with too many keys [1043 > 1000] + private static final Pattern TOO_MANY_PARTS_RE = Pattern.compile("too many keys \\[(\\d+) > (\\d+)]"); + + private final String maxRequestSize; + + public RequestErrorAdvice(@Value("${spring.servlet.multipart.max-request-size}") String maxRequestSize) { + this.maxRequestSize = maxRequestSize; + } + + @ExceptionHandler(MultipartException.class) + public ResponseEntity handleMultipartException(MultipartException ex) { + final Matcher tooManyParts = findTooManyParts(ex); + if (tooManyParts != null) { + final String message = String.format( + "The build request contains too many files (%s, the limit is %s). Reduce the number of files in the project extensions, or update the editor to a version that uploads the sources as a single archive.", + tooManyParts.group(1), tooManyParts.group(2)); + LOGGER.error(Markers.SERVER_ERROR, message, ex); + return textResponse(HttpStatus.PAYLOAD_TOO_LARGE, message); + } + + if (ex instanceof MaxUploadSizeExceededException) { + final String message = String.format("The build request is too large. Max allowed size is %s.", maxRequestSize); + LOGGER.error(Markers.SERVER_ERROR, message, ex); + return textResponse(HttpStatus.PAYLOAD_TOO_LARGE, message); + } + + final String message = "The build request is not a valid multipart request and could not be read by the server."; + LOGGER.error(Markers.SERVER_ERROR, message, ex); + return textResponse(HttpStatus.BAD_REQUEST, message); + } + + private static Matcher findTooManyParts(Throwable ex) { + for (Throwable cause = ex; cause != null; cause = cause.getCause()) { + if (cause.getMessage() != null) { + final Matcher matcher = TOO_MANY_PARTS_RE.matcher(cause.getMessage()); + if (matcher.find()) { + return matcher; + } + } + if (cause.getCause() == cause) { + break; + } + } + return null; + } + + private static ResponseEntity textResponse(HttpStatus status, String message) { + HttpHeaders headers = new HttpHeaders(); + headers.setContentType(MediaType.TEXT_PLAIN); + return new ResponseEntity<>(message, headers, status); + } +} diff --git a/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java b/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java new file mode 100644 index 00000000..b2a95467 --- /dev/null +++ b/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java @@ -0,0 +1,81 @@ +package com.defold.extender.jetty; + +import java.io.IOException; + +import org.eclipse.jetty.http.HttpException; +import org.eclipse.jetty.http.HttpHeader; +import org.eclipse.jetty.http.HttpStatus; +import org.eclipse.jetty.io.Content; +import org.eclipse.jetty.server.Request; +import org.eclipse.jetty.server.Response; +import org.eclipse.jetty.server.handler.ErrorHandler; +import org.eclipse.jetty.util.Callback; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import com.defold.extender.log.Markers; + +/** + * Error handler installed on the Jetty {@link org.eclipse.jetty.server.Server}. Jetty uses it for + * requests that fail before they enter the servlet context - malformed HTTP, too large headers, + * too long URI, unsupported HTTP version. Those never reach Spring, so neither the controller + * exception handlers nor {@link com.defold.extender.RequestErrorAdvice} can see them; without this + * handler they are answered with an HTML page and are not logged at all. + * + * Errors raised inside the servlet context still go through Spring Boot's context error handler. + */ +public class ExtenderJettyErrorHandler extends ErrorHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(ExtenderJettyErrorHandler.class); + + private static final String MIME_TYPE = "text/plain"; + + public ExtenderJettyErrorHandler() { + setShowStacks(false); + setShowCauses(false); + setShowMessageInTitle(false); + setDefaultResponseMimeType(MIME_TYPE); + } + + @Override + public boolean handle(Request request, Response response, Callback callback) throws Exception { + final String message = (String)request.getAttribute(ERROR_MESSAGE); + final Throwable cause = (Throwable)request.getAttribute(ERROR_EXCEPTION); + final int code = (cause instanceof HttpException httpException) ? httpException.getCode() : response.getStatus(); + + LOGGER.error(Markers.SERVER_ERROR, "Jetty rejected request {} {} from {} with status {}: {}", + request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), code, message, cause); + + return super.handle(request, response, callback); + } + + @Override + protected void generateResponse(Request request, Response response, int code, String message, Throwable cause, Callback callback) throws IOException { + response.getHeaders().put(HttpHeader.CONTENT_TYPE, MIME_TYPE + ";charset=utf-8"); + Content.Sink.write(response, true, describe(code), callback); + } + + /** + * The body the user gets to see. Only the status is derived from the failure, the details of + * what Jetty disliked stay in the log. + */ + static String describe(int code) { + final String explanation = switch (code) { + case HttpStatus.BAD_REQUEST_400 -> + "The server could not parse the request, so the build was never started. This usually means the request was truncated or malformed on the way to the server."; + case HttpStatus.REQUEST_TIMEOUT_408 -> + "The server timed out while waiting for the request to be sent."; + case HttpStatus.PAYLOAD_TOO_LARGE_413 -> + "The build request is too large."; + case HttpStatus.URI_TOO_LONG_414 -> + "The request URI is too long."; + case HttpStatus.REQUEST_HEADER_FIELDS_TOO_LARGE_431 -> + "The request headers are too large."; + case HttpStatus.HTTP_VERSION_NOT_SUPPORTED_505 -> + "The HTTP version used by the client is not supported by the server."; + default -> + "The request was rejected by the server before the build was started."; + }; + return String.format("%d %s%n%n%s%n", code, HttpStatus.getMessage(code), explanation); + } +} diff --git a/server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java b/server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java new file mode 100644 index 00000000..e6553766 --- /dev/null +++ b/server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java @@ -0,0 +1,38 @@ +package com.defold.extender.jetty; + +import org.eclipse.jetty.http.HttpFields; +import org.eclipse.jetty.server.Request; +import org.eclipse.jetty.server.handler.EventsHandler; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import com.defold.extender.log.Markers; + +/** + * Logs requests that fail on the Jetty side. This complements {@link ExtenderJettyErrorHandler}: + * the error handler only runs when Jetty generates an error response, while this handler also sees + * failures that never produce one - a client that aborts mid upload, an idle timeout, or a failure + * after the response was already committed. + */ +public class JettyRequestEventsHandler extends EventsHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(JettyRequestEventsHandler.class); + + // Compilation errors are reported as 422 by ExtenderController.handleExtenderException, which + // logs them with the full build output. No need to log them a second time here. + private static final int COMPILATION_ERROR_STATUS = 422; + + @Override + protected void onComplete(Request request, int status, HttpFields headers, Throwable failure) { + if (failure != null) { + LOGGER.error(Markers.SERVER_ERROR, "Request {} {} from {} failed with status {}", + request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), status, failure); + } else if (status >= 500) { + LOGGER.error(Markers.SERVER_ERROR, "Request {} {} from {} completed with status {}", + request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), status); + } else if (status >= 400 && status != COMPILATION_ERROR_STATUS) { + LOGGER.warn("Request {} {} from {} completed with status {}", + request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), status); + } + } +} diff --git a/server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java b/server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java new file mode 100644 index 00000000..5efa938a --- /dev/null +++ b/server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java @@ -0,0 +1,25 @@ +package com.defold.extender.jetty; + +import org.eclipse.jetty.server.Handler; +import org.springframework.boot.jetty.ConfigurableJettyWebServerFactory; +import org.springframework.boot.web.server.WebServerFactoryCustomizer; +import org.springframework.context.annotation.Bean; +import org.springframework.context.annotation.Configuration; + +@Configuration(proxyBeanMethods = false) +public class JettyServerConfiguration { + + @Bean + WebServerFactoryCustomizer extenderJettyCustomizer() { + return factory -> factory.addServerCustomizers(server -> { + // Spring Boot sets its own error handler on the servlet context (it drives the /error + // dispatch), the server level one is unused and is where pre-context errors end up. + server.setErrorHandler(new ExtenderJettyErrorHandler()); + + final JettyRequestEventsHandler eventsHandler = new JettyRequestEventsHandler(); + final Handler currentHandler = server.getHandler(); + eventsHandler.setHandler(currentHandler); + server.setHandler(eventsHandler); + }); + } +} diff --git a/server/src/main/resources/application.yml b/server/src/main/resources/application.yml index 871666d4..a7f2e2b3 100644 --- a/server/src/main/resources/application.yml +++ b/server/src/main/resources/application.yml @@ -1,7 +1,12 @@ server: port: 9000 + # Requests with larger headers are rejected by Jetty before any application code runs + max-http-request-header-size: 16KB jetty: connection-idle-timeout: 600000 + # Jetty uses maxFormKeys as the maximum number of multipart parts. The client uploads one + # part per file, so this is effectively the max number of files in a build request. + max-form-keys: 5000 extender: sdk: diff --git a/server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java b/server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java new file mode 100644 index 00000000..934fdc7c --- /dev/null +++ b/server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java @@ -0,0 +1,249 @@ +package com.defold.extender.jetty; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.junit.jupiter.api.Assertions.fail; + +import java.io.BufferedReader; +import java.io.IOException; +import java.io.InputStreamReader; +import java.io.OutputStream; +import java.net.Socket; +import java.nio.charset.StandardCharsets; +import java.util.List; +import java.util.concurrent.CopyOnWriteArrayList; + +import org.apache.http.HttpResponse; +import org.apache.http.client.methods.HttpGet; +import org.apache.http.client.methods.HttpPost; +import org.apache.http.client.methods.HttpUriRequest; +import org.apache.http.entity.ContentType; +import org.apache.http.entity.mime.MultipartEntityBuilder; +import org.apache.http.impl.client.CloseableHttpClient; +import org.apache.http.impl.client.HttpClients; +import org.apache.http.util.EntityUtils; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.parallel.Execution; +import org.junit.jupiter.api.parallel.ExecutionMode; +import org.slf4j.LoggerFactory; +import org.springframework.boot.SpringBootConfiguration; +import org.springframework.boot.autoconfigure.EnableAutoConfiguration; +import org.springframework.boot.test.context.SpringBootTest; +import org.springframework.boot.test.web.server.LocalServerPort; +import org.springframework.context.annotation.Bean; +import org.springframework.context.annotation.Import; +import org.springframework.security.config.annotation.web.builders.HttpSecurity; +import org.springframework.security.web.SecurityFilterChain; +import org.springframework.web.bind.annotation.PostMapping; +import org.springframework.web.bind.annotation.RestController; +import org.springframework.web.multipart.MultipartHttpServletRequest; + +import com.defold.extender.RequestErrorAdvice; + +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.AppenderBase; + +/** + * Runs a real Jetty (MockMvc never runs Jetty's multipart parser, so it cannot reproduce any of + * this) on a random port, with a minimal context instead of the full Extender application. Requests + * are sent with the same HTTP client the Extender client and the remote builder use. + */ +@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT, + classes = JettyErrorHandlingTest.TestApp.class, + properties = { + "server.jetty.max-form-keys=50", + "server.max-http-request-header-size=16KB" + }) +// The log assertions below observe loggers shared by the whole JVM, so the test methods of this +// class must not run next to each other (parallel execution is on by default, see +// junit-platform.properties). +@Execution(ExecutionMode.SAME_THREAD) +public class JettyErrorHandlingTest { + + private static final int MAX_PARTS = 50; + + @SpringBootConfiguration + @EnableAutoConfiguration + @Import({ JettyServerConfiguration.class, RequestErrorAdvice.class }) + static class TestApp { + + @Bean + SecurityFilterChain permitAll(HttpSecurity http) throws Exception { + return http + .csrf(csrf -> csrf.disable()) + .authorizeHttpRequests(requests -> requests.anyRequest().permitAll()) + .build(); + } + + @Bean + UploadController uploadController() { + return new UploadController(); + } + } + + @RestController + static class UploadController { + @PostMapping("/upload") + String upload(MultipartHttpServletRequest request) { + return String.valueOf(request.getFileMap().size()); + } + } + + private static final List> LOGGERS_UNDER_TEST = List.of( + ExtenderJettyErrorHandler.class, JettyRequestEventsHandler.class, RequestErrorAdvice.class); + + @LocalServerPort + private int port; + + private final List loggedMessages = new CopyOnWriteArrayList<>(); + private final AppenderBase appender = new AppenderBase<>() { + @Override + protected void append(ILoggingEvent event) { + loggedMessages.add(event.getFormattedMessage()); + } + }; + + @BeforeEach + public void captureLogs() { + loggedMessages.clear(); + appender.start(); + LOGGERS_UNDER_TEST.forEach(logger -> ((Logger)LoggerFactory.getLogger(logger)).addAppender(appender)); + } + + @AfterEach + public void releaseLogs() { + LOGGERS_UNDER_TEST.forEach(logger -> ((Logger)LoggerFactory.getLogger(logger)).detachAppender(appender)); + appender.stop(); + } + + @Test + public void uploadWithTooManyFilesIsRejectedWithAnExplanation() throws IOException { + Response response = upload(MAX_PARTS + 1); + + assertEquals(413, response.status()); + assertTrue(response.contentType().startsWith("text/plain"), "Unexpected content type: " + response.contentType()); + assertTrue(response.body().contains(String.format("too many files (%d, the limit is %d)", MAX_PARTS + 1, MAX_PARTS)), + "Unexpected body: " + response.body()); + + assertLogged("too many files"); + // The request completed inside the servlet context, so this also proves that the events + // handler is part of the handler chain. + assertLogged("completed with status 413"); + } + + @Test + public void uploadWithinTheLimitSucceeds() throws IOException { + Response response = upload(MAX_PARTS - 1); + + assertEquals(200, response.status()); + assertEquals(String.valueOf(MAX_PARTS - 1), response.body()); + } + + @Test + public void malformedMultipartBodiesAreRejectedWithAnExplanation() throws IOException { + // A body that never contains the announced boundary. Jetty fails to parse it before the + // request is mapped to a controller method. + String body = "not a multipart body\r\n"; + String response = sendRaw("POST /upload HTTP/1.1\r\n" + + "Host: localhost\r\n" + + "Content-Type: multipart/form-data; boundary=aBoundary\r\n" + + "Content-Length: " + body.length() + "\r\n" + + "\r\n" + + body); + + assertTrue(response.startsWith("HTTP/1.1 400"), "Unexpected response: " + response); + assertTrue(response.contains("not a valid multipart request"), "Unexpected response: " + response); + assertLogged("not a valid multipart request"); + } + + @Test + public void oversizedHeadersAreRejectedByTheJettyErrorHandler() throws IOException { + HttpGet request = new HttpGet(url("/upload")); + request.addHeader("X-Too-Large", "a".repeat(32 * 1024)); + + Response response = execute(request); + + assertEquals(431, response.status()); + assertTrue(response.contentType().startsWith("text/plain"), "Unexpected content type: " + response.contentType()); + assertTrue(response.body().contains("The request headers are too large"), "Unexpected body: " + response.body()); + assertLogged("Jetty rejected request GET /upload"); + } + + @Test + public void malformedRequestsAreRejectedByTheJettyErrorHandler() throws IOException { + String response = sendRaw("GET / HTTP/1.1\r\nHost: localhost\r\nthis-is-not-a-header\r\n\r\n"); + + assertTrue(response.startsWith("HTTP/1.1 400"), "Unexpected response: " + response); + assertTrue(response.contains("text/plain"), "Unexpected response: " + response); + assertTrue(response.contains("The server could not parse the request"), "Unexpected response: " + response); + assertLogged("Jetty rejected request"); + } + + private record Response(int status, String contentType, String body) {} + + /** + * Some of these messages are logged after the response has been written (the events handler is + * notified when the request is recycled), so give them a moment to arrive. + */ + private void assertLogged(String message) { + for (int attempt = 0; attempt < 100; attempt++) { + if (loggedMessages.stream().anyMatch(logged -> logged.contains(message))) { + return; + } + try { + Thread.sleep(20); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + break; + } + } + fail(String.format("Expected a log message containing '%s', but got: %s", message, loggedMessages)); + } + + private String url(String path) { + return String.format("http://localhost:%d%s", port, path); + } + + private Response upload(int fileCount) throws IOException { + MultipartEntityBuilder entityBuilder = MultipartEntityBuilder.create(); + for (int i = 0; i < fileCount; i++) { + final String filename = String.format("file%d.txt", i); + entityBuilder.addBinaryBody(filename, filename.getBytes(StandardCharsets.UTF_8), + ContentType.APPLICATION_OCTET_STREAM, filename); + } + + HttpPost request = new HttpPost(url("/upload")); + request.setEntity(entityBuilder.build()); + return execute(request); + } + + private Response execute(HttpUriRequest request) throws IOException { + try (CloseableHttpClient client = HttpClients.createDefault()) { + HttpResponse response = client.execute(request); + String contentType = response.getEntity().getContentType() == null + ? "" : response.getEntity().getContentType().getValue(); + return new Response(response.getStatusLine().getStatusCode(), contentType, + EntityUtils.toString(response.getEntity(), StandardCharsets.UTF_8).trim()); + } + } + + private String sendRaw(String request) throws IOException { + try (Socket socket = new Socket("localhost", port)) { + OutputStream output = socket.getOutputStream(); + output.write(request.getBytes(StandardCharsets.ISO_8859_1)); + output.flush(); + + StringBuilder response = new StringBuilder(); + try (BufferedReader reader = new BufferedReader(new InputStreamReader(socket.getInputStream(), StandardCharsets.ISO_8859_1))) { + String line; + while ((line = reader.readLine()) != null) { + response.append(line).append('\n'); + } + } + return response.toString(); + } + } +} From 1bd32585b4f6de9dc0bbf8c20d5c725c0358e978 Mon Sep 17 00:00:00 2001 From: Kharkunov Eugene Date: Sun, 30 Aug 2026 13:04:15 +0300 Subject: [PATCH 2/3] Cleanup + review fixes --- .../defold/extender/RequestErrorAdvice.java | 29 ++++++++------ .../jetty/ExtenderJettyErrorHandler.java | 24 ++++++----- .../jetty/JettyRequestEventsHandler.java | 40 ++++++++++++------- .../jetty/JettyServerConfiguration.java | 3 +- server/src/main/resources/application.yml | 5 +-- .../jetty/JettyErrorHandlingTest.java | 38 +++++++++++++----- 6 files changed, 86 insertions(+), 53 deletions(-) diff --git a/server/src/main/java/com/defold/extender/RequestErrorAdvice.java b/server/src/main/java/com/defold/extender/RequestErrorAdvice.java index 97a6b05c..d6e898cb 100644 --- a/server/src/main/java/com/defold/extender/RequestErrorAdvice.java +++ b/server/src/main/java/com/defold/extender/RequestErrorAdvice.java @@ -1,5 +1,8 @@ package com.defold.extender; +import java.util.Collections; +import java.util.IdentityHashMap; +import java.util.Set; import java.util.regex.Matcher; import java.util.regex.Pattern; @@ -15,8 +18,6 @@ import org.springframework.web.multipart.MaxUploadSizeExceededException; import org.springframework.web.multipart.MultipartException; -import com.defold.extender.log.Markers; - /** * Handles uploads that fail while Jetty parses the multipart body. Parsing happens in * DispatcherServlet.checkMultipart(), i.e. before the request is mapped to a controller method, so @@ -29,13 +30,15 @@ public class RequestErrorAdvice { private static final Logger LOGGER = LoggerFactory.getLogger(RequestErrorAdvice.class); - // Jetty caps the number of multipart parts at ServletContextHandler.getMaxFormKeys() - // (server.jetty.max-form-keys) and reports it as: Form with too many keys [1043 > 1000] + // Matches Jetty's message for the part limit: Form with too many keys [1043 > 1000] private static final Pattern TOO_MANY_PARTS_RE = Pattern.compile("too many keys \\[(\\d+) > (\\d+)]"); + private final String maxFileSize; private final String maxRequestSize; - public RequestErrorAdvice(@Value("${spring.servlet.multipart.max-request-size}") String maxRequestSize) { + public RequestErrorAdvice(@Value("${spring.servlet.multipart.max-file-size}") String maxFileSize, + @Value("${spring.servlet.multipart.max-request-size}") String maxRequestSize) { + this.maxFileSize = maxFileSize; this.maxRequestSize = maxRequestSize; } @@ -46,32 +49,32 @@ public ResponseEntity handleMultipartException(MultipartException ex) { final String message = String.format( "The build request contains too many files (%s, the limit is %s). Reduce the number of files in the project extensions, or update the editor to a version that uploads the sources as a single archive.", tooManyParts.group(1), tooManyParts.group(2)); - LOGGER.error(Markers.SERVER_ERROR, message, ex); + LOGGER.warn(message); return textResponse(HttpStatus.PAYLOAD_TOO_LARGE, message); } if (ex instanceof MaxUploadSizeExceededException) { - final String message = String.format("The build request is too large. Max allowed size is %s.", maxRequestSize); - LOGGER.error(Markers.SERVER_ERROR, message, ex); + // Spring raises this for both limits without saying which one was hit. + final String message = String.format("The build request is too large. Max allowed size is %s per file and %s per request.", + maxFileSize, maxRequestSize); + LOGGER.warn(message); return textResponse(HttpStatus.PAYLOAD_TOO_LARGE, message); } final String message = "The build request is not a valid multipart request and could not be read by the server."; - LOGGER.error(Markers.SERVER_ERROR, message, ex); + LOGGER.warn(message, ex); return textResponse(HttpStatus.BAD_REQUEST, message); } private static Matcher findTooManyParts(Throwable ex) { - for (Throwable cause = ex; cause != null; cause = cause.getCause()) { + final Set seen = Collections.newSetFromMap(new IdentityHashMap<>()); + for (Throwable cause = ex; cause != null && seen.add(cause); cause = cause.getCause()) { if (cause.getMessage() != null) { final Matcher matcher = TOO_MANY_PARTS_RE.matcher(cause.getMessage()); if (matcher.find()) { return matcher; } } - if (cause.getCause() == cause) { - break; - } } return null; } diff --git a/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java b/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java index b2a95467..da69df74 100644 --- a/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java +++ b/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java @@ -16,13 +16,12 @@ import com.defold.extender.log.Markers; /** - * Error handler installed on the Jetty {@link org.eclipse.jetty.server.Server}. Jetty uses it for - * requests that fail before they enter the servlet context - malformed HTTP, too large headers, + * Error handler installed on the Jetty {@link org.eclipse.jetty.server.Server}, i.e. the one used + * for requests that fail before they enter the servlet context - malformed HTTP, too large headers, * too long URI, unsupported HTTP version. Those never reach Spring, so neither the controller * exception handlers nor {@link com.defold.extender.RequestErrorAdvice} can see them; without this - * handler they are answered with an HTML page and are not logged at all. - * - * Errors raised inside the servlet context still go through Spring Boot's context error handler. + * handler they are answered with an HTML page and are not logged at all. Errors raised inside the + * context still go through Spring Boot's own context error handler. */ public class ExtenderJettyErrorHandler extends ErrorHandler { @@ -30,6 +29,8 @@ public class ExtenderJettyErrorHandler extends ErrorHandler { private static final String MIME_TYPE = "text/plain"; + private static final String LOG_MESSAGE = "Jetty rejected request {} {} from {} with status {}: {}"; + public ExtenderJettyErrorHandler() { setShowStacks(false); setShowCauses(false); @@ -43,8 +44,12 @@ public boolean handle(Request request, Response response, Callback callback) thr final Throwable cause = (Throwable)request.getAttribute(ERROR_EXCEPTION); final int code = (cause instanceof HttpException httpException) ? httpException.getCode() : response.getStatus(); - LOGGER.error(Markers.SERVER_ERROR, "Jetty rejected request {} {} from {} with status {}: {}", - request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), code, message, cause); + final Object[] details = { request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), code, message, cause }; + if (HttpStatus.isServerError(code)) { + LOGGER.error(Markers.SERVER_ERROR, LOG_MESSAGE, details); + } else { + LOGGER.warn(LOG_MESSAGE, details); + } return super.handle(request, response, callback); } @@ -55,10 +60,7 @@ protected void generateResponse(Request request, Response response, int code, St Content.Sink.write(response, true, describe(code), callback); } - /** - * The body the user gets to see. Only the status is derived from the failure, the details of - * what Jetty disliked stay in the log. - */ + /** The body the user gets to see. What exactly Jetty disliked stays in the log. */ static String describe(int code) { final String explanation = switch (code) { case HttpStatus.BAD_REQUEST_400 -> diff --git a/server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java b/server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java index e6553766..39abfe7a 100644 --- a/server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java +++ b/server/src/main/java/com/defold/extender/jetty/JettyRequestEventsHandler.java @@ -1,36 +1,46 @@ package com.defold.extender.jetty; -import org.eclipse.jetty.http.HttpFields; +import java.util.Set; + +import org.eclipse.jetty.http.HttpStatus; +import org.eclipse.jetty.server.Handler; import org.eclipse.jetty.server.Request; -import org.eclipse.jetty.server.handler.EventsHandler; +import org.eclipse.jetty.server.Response; +import org.eclipse.jetty.util.Callback; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import com.defold.extender.log.Markers; - /** * Logs requests that fail on the Jetty side. This complements {@link ExtenderJettyErrorHandler}: * the error handler only runs when Jetty generates an error response, while this handler also sees * failures that never produce one - a client that aborts mid upload, an idle timeout, or a failure - * after the response was already committed. + * after the response was already committed. All of those are client side problems, hence the + * warnings without com.defold.extender.log.Markers.SERVER_ERROR. */ -public class JettyRequestEventsHandler extends EventsHandler { +public class JettyRequestEventsHandler extends Handler.Wrapper { private static final Logger LOGGER = LoggerFactory.getLogger(JettyRequestEventsHandler.class); - // Compilation errors are reported as 422 by ExtenderController.handleExtenderException, which - // logs them with the full build output. No need to log them a second time here. - private static final int COMPILATION_ERROR_STATUS = 422; + // Already logged by ExtenderController's @ExceptionHandler methods, with more context than is + // available here, and for two of them with a SERVER_ERROR alert attached. + private static final Set STATUSES_LOGGED_BY_CONTROLLER = Set.of( + HttpStatus.UNPROCESSABLE_ENTITY_422, // handleExtenderException + HttpStatus.INTERNAL_SERVER_ERROR_500, // handleException + HttpStatus.NOT_IMPLEMENTED_501); // handleUsupportedExceptions @Override - protected void onComplete(Request request, int status, HttpFields headers, Throwable failure) { + public boolean handle(Request request, Response response, Callback callback) throws Exception { + // Not EventsHandler, which offers the same event only by wrapping the request and the + // response, adding an allocation to every chunk read and written. + Request.addCompletionListener(request, failure -> onComplete(request, response.getStatus(), failure)); + return super.handle(request, response, callback); + } + + private static void onComplete(Request request, int status, Throwable failure) { if (failure != null) { - LOGGER.error(Markers.SERVER_ERROR, "Request {} {} from {} failed with status {}", + LOGGER.warn("Request {} {} from {} failed with status {}", request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), status, failure); - } else if (status >= 500) { - LOGGER.error(Markers.SERVER_ERROR, "Request {} {} from {} completed with status {}", - request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), status); - } else if (status >= 400 && status != COMPILATION_ERROR_STATUS) { + } else if (status >= 400 && !STATUSES_LOGGED_BY_CONTROLLER.contains(status)) { LOGGER.warn("Request {} {} from {} completed with status {}", request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), status); } diff --git a/server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java b/server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java index 5efa938a..c1c624c2 100644 --- a/server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java +++ b/server/src/main/java/com/defold/extender/jetty/JettyServerConfiguration.java @@ -12,8 +12,7 @@ public class JettyServerConfiguration { @Bean WebServerFactoryCustomizer extenderJettyCustomizer() { return factory -> factory.addServerCustomizers(server -> { - // Spring Boot sets its own error handler on the servlet context (it drives the /error - // dispatch), the server level one is unused and is where pre-context errors end up. + // Must be the server level handler: the context one is Spring Boot's /error dispatch. server.setErrorHandler(new ExtenderJettyErrorHandler()); final JettyRequestEventsHandler eventsHandler = new JettyRequestEventsHandler(); diff --git a/server/src/main/resources/application.yml b/server/src/main/resources/application.yml index a7f2e2b3..52c0d1aa 100644 --- a/server/src/main/resources/application.yml +++ b/server/src/main/resources/application.yml @@ -1,11 +1,10 @@ server: port: 9000 - # Requests with larger headers are rejected by Jetty before any application code runs max-http-request-header-size: 16KB jetty: connection-idle-timeout: 600000 - # Jetty uses maxFormKeys as the maximum number of multipart parts. The client uploads one - # part per file, so this is effectively the max number of files in a build request. + # Jetty reuses maxFormKeys as the multipart part limit, i.e. the max number of files + # in a build request. max-form-keys: 5000 extender: diff --git a/server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java b/server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java index 934fdc7c..8a8c41a8 100644 --- a/server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java +++ b/server/src/test/java/com/defold/extender/jetty/JettyErrorHandlingTest.java @@ -1,6 +1,7 @@ package com.defold.extender.jetty; import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; import static org.junit.jupiter.api.Assertions.assertTrue; import static org.junit.jupiter.api.Assertions.fail; @@ -36,6 +37,8 @@ import org.springframework.context.annotation.Import; import org.springframework.security.config.annotation.web.builders.HttpSecurity; import org.springframework.security.web.SecurityFilterChain; +import org.springframework.http.ResponseEntity; +import org.springframework.web.bind.annotation.GetMapping; import org.springframework.web.bind.annotation.PostMapping; import org.springframework.web.bind.annotation.RestController; import org.springframework.web.multipart.MultipartHttpServletRequest; @@ -90,6 +93,11 @@ static class UploadController { String upload(MultipartHttpServletRequest request) { return String.valueOf(request.getFileMap().size()); } + + @GetMapping("/boom") + ResponseEntity boom() { + return ResponseEntity.internalServerError().body("boom"); + } } private static final List> LOGGERS_UNDER_TEST = List.of( @@ -129,8 +137,6 @@ public void uploadWithTooManyFilesIsRejectedWithAnExplanation() throws IOExcepti "Unexpected body: " + response.body()); assertLogged("too many files"); - // The request completed inside the servlet context, so this also proves that the events - // handler is part of the handler chain. assertLogged("completed with status 413"); } @@ -142,13 +148,24 @@ public void uploadWithinTheLimitSucceeds() throws IOException { assertEquals(String.valueOf(MAX_PARTS - 1), response.body()); } + @Test + public void statusesLoggedByTheControllerAreNotLoggedAgain() throws IOException { + assertEquals(500, execute(new HttpGet(url("/boom"))).status()); + // Sequential, so the 500 has certainly been seen by the time the 404 is logged. + assertEquals(404, execute(new HttpGet(url("/not-mapped"))).status()); + + assertLogged("completed with status 404"); + assertFalse(loggedMessages.stream().anyMatch(logged -> logged.contains("status 500")), + "The 500 is logged by ExtenderController's exception handlers, not here: " + loggedMessages); + } + @Test public void malformedMultipartBodiesAreRejectedWithAnExplanation() throws IOException { - // A body that never contains the announced boundary. Jetty fails to parse it before the - // request is mapped to a controller method. + // A body that never contains the announced boundary. String body = "not a multipart body\r\n"; String response = sendRaw("POST /upload HTTP/1.1\r\n" + "Host: localhost\r\n" + + "Connection: close\r\n" + "Content-Type: multipart/form-data; boundary=aBoundary\r\n" + "Content-Length: " + body.length() + "\r\n" + "\r\n" @@ -174,7 +191,7 @@ public void oversizedHeadersAreRejectedByTheJettyErrorHandler() throws IOExcepti @Test public void malformedRequestsAreRejectedByTheJettyErrorHandler() throws IOException { - String response = sendRaw("GET / HTTP/1.1\r\nHost: localhost\r\nthis-is-not-a-header\r\n\r\n"); + String response = sendRaw("GET / HTTP/1.1\r\nHost: localhost\r\nConnection: close\r\nthis-is-not-a-header\r\n\r\n"); assertTrue(response.startsWith("HTTP/1.1 400"), "Unexpected response: " + response); assertTrue(response.contains("text/plain"), "Unexpected response: " + response); @@ -184,10 +201,7 @@ public void malformedRequestsAreRejectedByTheJettyErrorHandler() throws IOExcept private record Response(int status, String contentType, String body) {} - /** - * Some of these messages are logged after the response has been written (the events handler is - * notified when the request is recycled), so give them a moment to arrive. - */ + /** Some of these are logged after the response is written, so give them a moment to arrive. */ private void assertLogged(String message) { for (int attempt = 0; attempt < 100; attempt++) { if (loggedMessages.stream().anyMatch(logged -> logged.contains(message))) { @@ -230,8 +244,14 @@ private Response execute(HttpUriRequest request) throws IOException { } } + /** + * Reads until the server closes the connection, so every request passed in must ask for + * "Connection: close" - the timeout is there to fail fast rather than stall a CI run for the + * ten minute idle timeout if one ever does not. + */ private String sendRaw(String request) throws IOException { try (Socket socket = new Socket("localhost", port)) { + socket.setSoTimeout(10_000); OutputStream output = socket.getOutputStream(); output.write(request.getBytes(StandardCharsets.ISO_8859_1)); output.flush(); From ca70b92e0eec75c6525bf9354cfdd143cbf4f4f0 Mon Sep 17 00:00:00 2001 From: Kharkunov Eugene Date: Sun, 30 Aug 2026 13:20:43 +0300 Subject: [PATCH 3/3] Fix codeql comments --- .../defold/extender/jetty/ExtenderJettyErrorHandler.java | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java b/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java index da69df74..1cabfbe1 100644 --- a/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java +++ b/server/src/main/java/com/defold/extender/jetty/ExtenderJettyErrorHandler.java @@ -44,11 +44,12 @@ public boolean handle(Request request, Response response, Callback callback) thr final Throwable cause = (Throwable)request.getAttribute(ERROR_EXCEPTION); final int code = (cause instanceof HttpException httpException) ? httpException.getCode() : response.getStatus(); - final Object[] details = { request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), code, message, cause }; if (HttpStatus.isServerError(code)) { - LOGGER.error(Markers.SERVER_ERROR, LOG_MESSAGE, details); + LOGGER.error(Markers.SERVER_ERROR, LOG_MESSAGE, + request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), code, message, cause); } else { - LOGGER.warn(LOG_MESSAGE, details); + LOGGER.warn(LOG_MESSAGE, + request.getMethod(), request.getHttpURI(), Request.getRemoteAddr(request), code, message, cause); } return super.handle(request, response, callback);