diff --git a/.github/workflows/test.yaml b/.github/workflows/test.yaml index 6a001f709..eafb7e87a 100644 --- a/.github/workflows/test.yaml +++ b/.github/workflows/test.yaml @@ -41,11 +41,12 @@ jobs: with: distribution: 'temurin' java-version: '17' - - name: Setup Gradle, execute tests & verify overall coverage + - name: Setup Gradle uses: gradle/gradle-build-action@v2 with: - arguments: test jacocoTestReport jacocoTestCoverageVerification gradle-version: 8.2 + - name: Execute tests & verify overall coverage + run: gradle test jacocoTestReport jacocoTestCoverageVerification - name: Publish Test Report uses: mikepenz/action-junit-report@v4 if: success() || failure() # always run even if the previous step fails @@ -62,6 +63,6 @@ jobs: title: Code Coverage - name: Fail when coverage of changed files is too low run: | - CHANGED_FILES_FAILED=$(echo '${{ steps.jacoco.outputs.coverage-changed-files }} < ${{ env.MIN_COVERAGE_CHANGED_FILES }}' | bc) - [[ $CHANGED_FILES_FAILED -ne 0 ]] && echo 'Changed files coverage ${{ steps.jacoco.outputs.coverage-changed-files }}% is smaller than required ${{ env.MIN_COVERAGE_CHANGED_FILES }}%' - [[ $CHANGED_FILES_FAILED -ne 0 ]] && exit 1 || exit 0 \ No newline at end of file + CHANGED_FILES_FAILED=$(echo '${{ steps.jacoco.outputs.coverage-changed-files }} < ${{ env.MIN_COVERAGE_CHANGED_FILES }}' | bc) + [[ $CHANGED_FILES_FAILED -ne 0 ]] && echo 'Changed files coverage ${{ steps.jacoco.outputs.coverage-changed-files }}% is smaller than required ${{ env.MIN_COVERAGE_CHANGED_FILES }}%' + [[ $CHANGED_FILES_FAILED -ne 0 ]] && exit 1 || exit 0 \ No newline at end of file diff --git a/build.gradle.kts b/build.gradle.kts index 2657268ab..24890e3f6 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -1,8 +1,10 @@ @file:Suppress("PropertyName") +import org.gradle.api.tasks.testing.logging.TestExceptionFormat import java.net.URI import java.time.LocalDateTime import java.time.format.DateTimeFormatter +import org.gradle.kotlin.dsl.KotlinClosure2 repositories { maven { @@ -30,7 +32,7 @@ version = rootProject.properties["version"] as String val jetbrains_annotations = "org.jetbrains:annotations:24.0.1" -val vertx_version = "4.4.5" +val vertx_version = "4.5.0" val vertx_core = "io.vertx:vertx-core:$vertx_version" val vertx_config = "io.vertx:vertx-config:$vertx_version" val vertx_auth_jwt = "io.vertx:vertx-auth-jwt:$vertx_version" @@ -105,6 +107,7 @@ val mockito = "org.mockito:mockito-core:3.12.4" val flipkart_zjsonpatch = "com.flipkart.zjsonpatch:zjsonpatch:0.4.13" val json_assert = "org.skyscreamer:jsonassert:1.5.1" +val resillience4j_retry = "io.github.resilience4j:resilience4j-retry:2.0.0" val mavenUrl = rootProject.properties["mavenUrl"] as String val mavenUser = rootProject.properties["mavenUser"] as String @@ -185,7 +188,17 @@ subprojects { test { maxHeapSize = "4g" useJUnitPlatform() - testLogging.showStandardStreams = true + testLogging { + showStandardStreams = true + exceptionFormat = TestExceptionFormat.FULL + events("standardOut", "started", "passed", "skipped", "failed") + } + afterTest(KotlinClosure2( + { descriptor: TestDescriptor, result: TestResult -> + val totalTime = result.endTime - result.startTime + println("Total time of $descriptor.name was $totalTime") + } + )) } compileJava { @@ -451,6 +464,7 @@ project(":here-naksha-lib-handlers") { implementation(vertx_web_openapi) testImplementation(json_assert) + testImplementation(resillience4j_retry) } setOverallCoverage(0.25) // only increasing allowed! } diff --git a/here-naksha-app-service/src/main/java/com/here/naksha/app/service/NakshaApp.java b/here-naksha-app-service/src/main/java/com/here/naksha/app/service/NakshaApp.java index 93344869c..44f41e558 100644 --- a/here-naksha-app-service/src/main/java/com/here/naksha/app/service/NakshaApp.java +++ b/here-naksha-app-service/src/main/java/com/here/naksha/app/service/NakshaApp.java @@ -74,7 +74,6 @@ public final class NakshaApp extends Thread { * @param args The console arguments given. */ public static void main(@NotNull String... args) { - System.out.println("args: " + args); if (args.length < 1) { printUsage(); System.exit(1); @@ -121,8 +120,6 @@ private static void printUsage() { final String cfgId; final String url; - - System.out.println("args: " + args); switch (args.length) { case 1 -> { cfgId = args[0]; diff --git a/here-naksha-app-service/src/main/java/com/here/naksha/app/service/http/NakshaHttpVerticle.java b/here-naksha-app-service/src/main/java/com/here/naksha/app/service/http/NakshaHttpVerticle.java index a4e99b2b8..2514f7613 100644 --- a/here-naksha-app-service/src/main/java/com/here/naksha/app/service/http/NakshaHttpVerticle.java +++ b/here-naksha-app-service/src/main/java/com/here/naksha/app/service/http/NakshaHttpVerticle.java @@ -42,7 +42,13 @@ import com.here.naksha.app.service.AbstractNakshaHubVerticle; import com.here.naksha.app.service.NakshaApp; -import com.here.naksha.app.service.http.apis.*; +import com.here.naksha.app.service.http.apis.Api; +import com.here.naksha.app.service.http.apis.EventHandlerApi; +import com.here.naksha.app.service.http.apis.HealthApi; +import com.here.naksha.app.service.http.apis.ReadFeatureApi; +import com.here.naksha.app.service.http.apis.SpaceApi; +import com.here.naksha.app.service.http.apis.StorageApi; +import com.here.naksha.app.service.http.apis.WriteFeatureApi; import com.here.naksha.app.service.http.auth.NakshaJwtAuthHandler; import com.here.naksha.lib.core.AbstractTask; import com.here.naksha.lib.core.INaksha; @@ -60,9 +66,11 @@ import com.here.naksha.lib.core.util.MIMEType; import com.here.naksha.lib.hub.NakshaHubConfig; import io.netty.handler.codec.http.HttpResponseStatus; +import io.vertx.core.Handler; import io.vertx.core.MultiMap; import io.vertx.core.Promise; import io.vertx.core.buffer.Buffer; +import io.vertx.core.http.HttpConnection; import io.vertx.core.http.HttpMethod; import io.vertx.core.http.HttpServerOptions; import io.vertx.core.http.HttpServerResponse; @@ -216,21 +224,24 @@ public void start(final @NotNull Promise startPromise) { // round-robin strategy. // // https://vertx.io/docs/vertx-core/java/#_server_sharing - vertx.createHttpServer(SERVER_OPTIONS).requestHandler(router).listen(hubConfig.httpPort, result -> { - if (result.succeeded()) { - log.atInfo() - .setMessage("HTTP Server started on port {}") - .addArgument(hubConfig.httpPort) - .log(); - startPromise.complete(); - } else { - log.atError() - .setMessage("An error occurred, during the initialization of the server.") - .setCause(result.cause()) - .log(); - startPromise.fail(result.cause()); - } - }); + vertx.createHttpServer(SERVER_OPTIONS) + .requestHandler(router) + .connectionHandler(loggingConnectionHandler()) + .listen(hubConfig.httpPort, result -> { + if (result.succeeded()) { + log.atInfo() + .setMessage("HTTP Server started on port {}") + .addArgument(hubConfig.httpPort) + .log(); + startPromise.complete(); + } else { + log.atError() + .setMessage("An error occurred, during the initialization of the server.") + .setCause(result.cause()) + .log(); + startPromise.fail(result.cause()); + } + }); } catch (Throwable t) { log.atError() .setMessage( @@ -327,7 +338,8 @@ private void notFoundHandler(final @NotNull RoutingContext routingContext) { * * @param routingContext The routing context. */ - private void onHeadersEnd(final @NotNull RoutingContext routingContext) {} + private void onHeadersEnd(final @NotNull RoutingContext routingContext) { + } /** * An end handler for the response. This will be called when the response is disposed to allow consistent cleanup of the response. @@ -396,6 +408,15 @@ private void onNewRequest(final @NotNull RoutingContext routingContext) { routingContext.next(); } + /** + * @return simple http connection handler that logs closing and failing connections + */ + private Handler loggingConnectionHandler() { + return httpConnection -> httpConnection + .closeHandler(v -> log.info("Closing connection")) + .exceptionHandler(t -> log.info("Connection exception", t)); + } + private static final Pattern FATAL_ERROR_MSG_PATTERN = Pattern.compile("^[0-9a-zA-Z.-_\\-]+$"); /** @@ -553,7 +574,7 @@ public void sendErrorResponse(@NotNull RoutingContext routingContext, @NotNull T /** * Prepare XyzFeatureCollection response by extracting feature results from ModifyFeaturesResp object * - * @param modifyResponse The object to extract feature results from + * @param modifyResponse The object to extract feature results from * @return The XyzFeatureCollection response containing list of inserted/updated/delete features */ public XyzFeatureCollection transformModifyResponse(@NotNull ModifyFeaturesResp modifyResponse) { @@ -588,6 +609,7 @@ public XyzResponse sendXyzResponse( @NotNull RoutingContext routingContext, @Nullable HttpResponseType responseType, @NotNull XyzResponse response) { + log.info("SendXyzResponse start on path {}", routingContext.request().path()); // TODO(Kuba): remove this line try { final String etag = response.getEtag(); if (etag != null) { @@ -680,7 +702,11 @@ public void sendRawResponse( final HttpServerResponse httpResponse = routingContext.response(); httpResponse.setStatusCode(status.code()).setStatusMessage(status.reasonPhrase()); httpResponse.putHeader(STREAM_ID, streamId(routingContext)); + log.info("Sending raw response on path {}", routingContext.request().path()); // TODO(Kuba): remove this line if (content == null || content.length() == 0) { + log.info( + "Empty content served from path {}", + routingContext.request().path()); // TODO(Kuba): remove this line httpResponse.end(); } else { if (contentType != null) { @@ -700,4 +726,16 @@ public void sendRawResponse( // ctx.setAuthor(); return ctx; } + + @Override + public void stop() throws Exception { + log.info("Stop (no params) called on {}", this.getClass().getSimpleName()); // TODO(Kuba): remove this line + super.stop(); + } + + @Override + public void stop(Promise stopPromise) throws Exception { + log.info("Stop (with promise) called on {}", this.getClass().getSimpleName()); // TODO(Kuba): remove this line + super.stop(stopPromise); + } } diff --git a/here-naksha-app-service/src/test/java/com/here/naksha/app/common/NakshaTestWebClient.java b/here-naksha-app-service/src/test/java/com/here/naksha/app/common/NakshaTestWebClient.java index 137e63e21..40cda2743 100644 --- a/here-naksha-app-service/src/test/java/com/here/naksha/app/common/NakshaTestWebClient.java +++ b/here-naksha-app-service/src/test/java/com/here/naksha/app/common/NakshaTestWebClient.java @@ -21,6 +21,10 @@ import static com.here.naksha.app.common.TestUtil.HDR_STREAM_ID; import static java.net.http.HttpClient.Version.HTTP_1_1; +import io.github.resilience4j.core.functions.CheckedFunction; +import io.github.resilience4j.retry.Retry; +import io.github.resilience4j.retry.RetryConfig; +import io.github.resilience4j.retry.RetryRegistry; import java.io.IOException; import java.net.URI; import java.net.URISyntaxException; @@ -29,21 +33,28 @@ import java.net.http.HttpRequest; import java.net.http.HttpRequest.BodyPublishers; import java.net.http.HttpResponse; +import java.net.http.HttpTimeoutException; import java.time.Duration; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class NakshaTestWebClient { + private static final Logger logger = LoggerFactory.getLogger(NakshaTestWebClient.class); private static final String NAKSHA_HTTP_URI = "http://localhost:8080/"; private static final Duration CONNECT_TIMEOUT = Duration.ofSeconds(10); private static final Duration SOCKET_TIMEOUT = Duration.ofSeconds(2); private final HttpClient httpClient; + private final RetryRegistry retryRegistry; + public NakshaTestWebClient() { httpClient = HttpClient.newBuilder() .version(HTTP_1_1) .connectTimeout(CONNECT_TIMEOUT) .build(); + retryRegistry = configureRetryRegistry(); } public HttpResponse get(String subPath, String streamId) throws URISyntaxException { @@ -76,13 +87,20 @@ public HttpResponse put(String subPath, String jsonBody, String streamId } private HttpResponse send(HttpRequest request) { + String retryId = retryIdForRequest(request); + CheckedFunction> responseSupplier = + Retry.decorateCheckedFunction(retry(retryId), this::sendOnce); try { - return httpClient.send(request, HttpResponse.BodyHandlers.ofString()); - } catch (IOException | InterruptedException e) { - throw new RequestException(request, e); + return responseSupplier.apply(request); + } catch (Throwable e) { + throw new RuntimeException("Applying retry (%s) failed".formatted(retryId), e); } } + private HttpResponse sendOnce(HttpRequest request) throws IOException, InterruptedException { + return httpClient.send(request, HttpResponse.BodyHandlers.ofString()); + } + private HttpRequest.Builder requestBuilder() { return HttpRequest.newBuilder().version(Version.HTTP_1_1).timeout(SOCKET_TIMEOUT); } @@ -91,15 +109,21 @@ private URI nakshaPath(String subPath) throws URISyntaxException { return new URI(NAKSHA_HTTP_URI + subPath); } - static class RequestException extends RuntimeException { + private Retry retry(String name) { + Retry retry = retryRegistry.retry(name); + retry.getEventPublisher().onRetry(ev -> logger.info("Retry triggereed: {}", name)); + return retry; + } - public RequestException(HttpRequest request, Throwable cause) { - super(msg(request), cause); - } + private static String retryIdForRequest(HttpRequest request) { + return "%s_%s_retry".formatted(request.method(), request.uri().toString()); + } - private static String msg(HttpRequest request) { - return "Request to Naksha failed, method: %s, uri: %s" - .formatted(request.method(), request.uri().toString()); - } + private static RetryRegistry configureRetryRegistry() { + RetryConfig config = RetryConfig.custom() + .maxAttempts(3) + .retryExceptions(HttpTimeoutException.class) + .build(); + return RetryRegistry.of(config); } }