From 185ffffca8f7e8c4bf61f39a43fe0244c0585383 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Weber?= Date: Thu, 6 Jun 2024 16:47:20 +0200 Subject: [PATCH 1/2] #585 Fix request logging for delta requests --- .../gateleen/delta/DeltaHandler.java | 33 ++++++++++++++++--- .../gateleen/delta/DeltaHandlerTest.java | 23 ++++++++----- .../gateleen/logging/LoggingHandler.java | 8 +++++ .../swisspush/gateleen/playground/Server.java | 3 +- .../org/swisspush/gateleen/AbstractTest.java | 2 +- 5 files changed, 54 insertions(+), 15 deletions(-) diff --git a/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java b/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java index fa37b8cb..2260d34a 100755 --- a/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java +++ b/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java @@ -6,6 +6,8 @@ import io.vertx.core.AsyncResult; import io.vertx.core.Handler; import io.vertx.core.MultiMap; +import io.vertx.core.Vertx; +import io.vertx.core.buffer.Buffer; import io.vertx.core.http.*; import io.vertx.core.json.JsonArray; import io.vertx.core.json.JsonObject; @@ -17,6 +19,9 @@ import org.swisspush.gateleen.core.util.*; import org.swisspush.gateleen.core.util.ExpansionDeltaUtil.CollectionResourceContainer; import org.swisspush.gateleen.core.util.ExpansionDeltaUtil.SlashHandling; +import org.swisspush.gateleen.logging.LogAppenderRepository; +import org.swisspush.gateleen.logging.LoggingHandler; +import org.swisspush.gateleen.logging.LoggingResourceManager; import org.swisspush.gateleen.routing.Router; import org.swisspush.gateleen.routing.Rule; import org.swisspush.gateleen.routing.RuleFeaturesProvider; @@ -24,6 +29,7 @@ import java.util.*; +import static org.swisspush.gateleen.logging.LoggingHandler.SKIP_LOGGING_HEADER; import static org.swisspush.gateleen.routing.RuleFeatures.Feature.DELTA_ON_BACKEND; /** @@ -54,18 +60,28 @@ public class DeltaHandler implements RuleProvider.RuleChangesObserver { private boolean rejectLimitOffsetRequests; private RuleProvider ruleProvider; + + private Vertx vertx; + private LoggingResourceManager loggingResourceManager; + private LogAppenderRepository logAppenderRepository; private RuleFeaturesProvider ruleFeaturesProvider = new RuleFeaturesProvider(new ArrayList<>()); - public DeltaHandler(RedisProvider redisProvider, HttpClient httpClient, RuleProvider ruleProvider) { - this(redisProvider, httpClient, ruleProvider, false); + public DeltaHandler(Vertx vertx, RedisProvider redisProvider, HttpClient httpClient, RuleProvider ruleProvider, + LoggingResourceManager loggingResourceManager, LogAppenderRepository logAppenderRepository) { + this(vertx,redisProvider, httpClient, ruleProvider, loggingResourceManager, logAppenderRepository, false); } - public DeltaHandler(RedisProvider redisProvider, HttpClient httpClient, RuleProvider ruleProvider, boolean rejectLimitOffsetRequests) { + public DeltaHandler(Vertx vertx, RedisProvider redisProvider, HttpClient httpClient, RuleProvider ruleProvider, + LoggingResourceManager loggingResourceManager, LogAppenderRepository logAppenderRepository, + boolean rejectLimitOffsetRequests) { + this.vertx = vertx; this.redisProvider = redisProvider; this.httpClient = httpClient; this.rejectLimitOffsetRequests = rejectLimitOffsetRequests; this.ruleProvider = ruleProvider; + this.loggingResourceManager = loggingResourceManager; + this.logAppenderRepository = logAppenderRepository; this.ruleProvider.registerObserver(this); } @@ -284,6 +300,9 @@ private DeltaResourcesContainer getDeltaResourceNames(List subResourceNa private void handleCollectionGET(final HttpServerRequest request, final String updateId, final Logger log) { request.pause(); + final LoggingHandler loggingHandler = new LoggingHandler(loggingResourceManager, logAppenderRepository, request, vertx.eventBus()); + loggingHandler.request(request.headers()); + final HttpMethod method = HttpMethod.GET; final String targetUri = ExpansionDeltaUtil.constructRequestUri(request.path(), request.params(), null, null, SlashHandling.KEEP); log.debug("constructed uri for request: {}", targetUri); @@ -299,6 +318,7 @@ private void handleCollectionGET(final HttpServerRequest request, final String u cReq.headers().setAll(request.headers()); // add a marker header to signalize, that in the next loop of the mainverticle we should pass the deltahandler cReq.headers().set(DELTA_BACKEND_HEADER, ""); + cReq.headers().set(SKIP_LOGGING_HEADER, "true"); cReq.headers().set("Accept", "application/json"); cReq.setChunked(true); request.handler(cReq::write); @@ -307,6 +327,8 @@ private void handleCollectionGET(final HttpServerRequest request, final String u HttpClientResponse cRes = asyncResult1.result(); HttpServerRequestUtil.prepareResponse(request, cRes); + loggingHandler.setResponse(cRes); + if (cRes.headers().contains(DELTA_HEADER)) { cRes.handler(data -> request.response().write(data)); cRes.endHandler(v1 -> request.response().end()); @@ -345,9 +367,12 @@ private void handleCollectionGET(final HttpServerRequest request, final String u JsonObject result = buildResultJsonObject(deltaResourcesContainer.getResourceNames(), dataContainer.getCollectionName()); + String responseBody = result.toString(); request.response().putHeader(DELTA_HEADER, "" + deltaResourcesContainer.getMaxUpdateId()); - request.response().end(result.toString()); + loggingHandler.appendResponsePayload(Buffer.buffer(responseBody)); + loggingHandler.log(); + request.response().end(responseBody); })).onFailure(event -> { log.error("Redis: handleCollectionGET failed", event); handleError(request, "error reading delta information"); diff --git a/gateleen-delta/src/test/java/org/swisspush/gateleen/delta/DeltaHandlerTest.java b/gateleen-delta/src/test/java/org/swisspush/gateleen/delta/DeltaHandlerTest.java index d9cdddfd..ef954629 100644 --- a/gateleen-delta/src/test/java/org/swisspush/gateleen/delta/DeltaHandlerTest.java +++ b/gateleen-delta/src/test/java/org/swisspush/gateleen/delta/DeltaHandlerTest.java @@ -1,9 +1,6 @@ package org.swisspush.gateleen.delta; -import io.vertx.core.AsyncResult; -import io.vertx.core.Future; -import io.vertx.core.Handler; -import io.vertx.core.MultiMap; +import io.vertx.core.*; import io.vertx.core.http.HttpMethod; import io.vertx.core.http.HttpServerRequest; import io.vertx.core.http.HttpServerResponse; @@ -19,6 +16,8 @@ import org.swisspush.gateleen.core.http.DummyHttpServerResponse; import org.swisspush.gateleen.core.redis.RedisProvider; import org.swisspush.gateleen.core.util.StatusCode; +import org.swisspush.gateleen.logging.LogAppenderRepository; +import org.swisspush.gateleen.logging.LoggingResourceManager; import org.swisspush.gateleen.routing.Router; import org.swisspush.gateleen.routing.Rule; import org.swisspush.gateleen.routing.RuleProvider; @@ -36,6 +35,9 @@ public class DeltaHandlerTest { private RedisAPI redisAPI; private RedisProvider redisProvider; private RuleProvider ruleProvider; + private Vertx vertx; + private LoggingResourceManager loggingResourceManager; + private LogAppenderRepository logAppenderRepository; private Router router = mock(Router.class); private HttpServerRequest request; private HttpServerResponse response; @@ -44,6 +46,9 @@ public class DeltaHandlerTest { @Before public void before() { redisAPI = mock(RedisAPI.class); + vertx = mock(Vertx.class); + loggingResourceManager = mock(LoggingResourceManager.class); + logAppenderRepository = mock(LogAppenderRepository.class); redisProvider = mock(RedisProvider.class); when(redisProvider.redis()).thenReturn(Future.succeededFuture(redisAPI)); @@ -69,7 +74,7 @@ public void before() { @Test public void testIsDeltaRequest(TestContext context) { - DeltaHandler deltaHandler = new DeltaHandler(redisProvider, null, ruleProvider); + DeltaHandler deltaHandler = new DeltaHandler(vertx, redisProvider, null, ruleProvider, loggingResourceManager, logAppenderRepository); deltaHandler.rulesChanged(List.of( rule("/gateleen/server/res_1", false), rule("/gateleen/server/res_2", true)) @@ -152,7 +157,7 @@ public void testIsDeltaRequest(TestContext context) { @Test public void testDeltaNoExpiry() { - DeltaHandler deltaHandler = new DeltaHandler(redisProvider, null, ruleProvider); + DeltaHandler deltaHandler = new DeltaHandler(vertx, redisProvider, null, ruleProvider, loggingResourceManager, logAppenderRepository); deltaHandler.handle(request, router); verify(redisAPI, times(1)).set(eq(Arrays.asList("delta:resources:a:b:c", "555")), any()); @@ -163,7 +168,7 @@ public void testDeltaNoExpiry() { public void testDeltaWithExpiry() { requestHeaders.add("x-expire-after", "123"); - DeltaHandler deltaHandler = new DeltaHandler(redisProvider, null, ruleProvider); + DeltaHandler deltaHandler = new DeltaHandler(vertx, redisProvider, null, ruleProvider, loggingResourceManager, logAppenderRepository); deltaHandler.handle(request, router); verify(redisAPI, times(1)).setex(eq("delta:resources:a:b:c"), eq("123"), eq("555"), any()); @@ -182,7 +187,7 @@ public void testFailingRedisProviderAccess(TestContext context) { ArgumentCaptor bodyCaptor = ArgumentCaptor.forClass(String.class); when(request.response().end(bodyCaptor.capture())).thenReturn(Future.succeededFuture()); - DeltaHandler deltaHandler = new DeltaHandler(redisProvider, null, ruleProvider); + DeltaHandler deltaHandler = new DeltaHandler(vertx, redisProvider, null, ruleProvider, loggingResourceManager, logAppenderRepository); deltaHandler.handle(request, router); context.assertEquals(StatusCode.INTERNAL_SERVER_ERROR.getStatusCode(), statusCodeCaptor.getValue(), "StatusCode should be 500"); @@ -191,7 +196,7 @@ public void testFailingRedisProviderAccess(TestContext context) { @Test public void testRejectLimitOffsetParameters(TestContext context) { - DeltaHandler deltaHandler = new DeltaHandler(redisProvider, null, ruleProvider, true); + DeltaHandler deltaHandler = new DeltaHandler(vertx, redisProvider, null, ruleProvider, loggingResourceManager, logAppenderRepository, true); final DummyHttpServerResponse response = new DummyHttpServerResponse(); DeltaRequest request = new DeltaRequest(MultiMap.caseInsensitiveMultiMap() .add("delta", "0") diff --git a/gateleen-logging/src/main/java/org/swisspush/gateleen/logging/LoggingHandler.java b/gateleen-logging/src/main/java/org/swisspush/gateleen/logging/LoggingHandler.java index dfe9e320..094d9322 100755 --- a/gateleen-logging/src/main/java/org/swisspush/gateleen/logging/LoggingHandler.java +++ b/gateleen-logging/src/main/java/org/swisspush/gateleen/logging/LoggingHandler.java @@ -64,6 +64,8 @@ public class LoggingHandler { private static final String ADDRESS = "address"; private static final String DEFAULT = "default"; + public static final String SKIP_LOGGING_HEADER = "x-skip-request-log"; + private Map loggers = new HashMap<>(); private Logger log; @@ -76,6 +78,12 @@ public LoggingHandler(LoggingResourceManager loggingResourceManager, LogAppender this.log = RequestLoggerFactory.getLogger(LoggingHandler.class, request); ((org.apache.logging.log4j.core.Logger) LogManager.getLogger(DEFAULT_LOGGER)).setAdditive(false); boolean stopValidation = false; + + if(request.headers().get(SKIP_LOGGING_HEADER) != null) { + log.info("request will not be logged because of skip log request header"); + return; + } + for (Map payloadFilter : loggingResource.getPayloadFilters()) { if (active || stopValidation) { break; diff --git a/gateleen-playground/src/main/java/org/swisspush/gateleen/playground/Server.java b/gateleen-playground/src/main/java/org/swisspush/gateleen/playground/Server.java index 4958f46f..2559fd4c 100755 --- a/gateleen-playground/src/main/java/org/swisspush/gateleen/playground/Server.java +++ b/gateleen-playground/src/main/java/org/swisspush/gateleen/playground/Server.java @@ -215,7 +215,8 @@ public void start() { RuleProvider ruleProvider = new RuleProvider(vertx, RULES_ROOT, storage, props); - deltaHandler = new DeltaHandler(redisProvider, selfClient, ruleProvider, true); + deltaHandler = new DeltaHandler(vertx, redisProvider, selfClient, ruleProvider, loggingResourceManager, + logAppenderRepository, true); expansionHandler = new ExpansionHandler(ruleProvider, selfClient, props, ROOT); copyResourceHandler = new CopyResourceHandler(selfClient, exceptionFactory, SERVER_ROOT + "/v1/copy"); monitoringHandler = new MonitoringHandler(vertx, storage, PREFIX, SERVER_ROOT + "/monitoring/rpr"); diff --git a/gateleen-test/src/test/java/org/swisspush/gateleen/AbstractTest.java b/gateleen-test/src/test/java/org/swisspush/gateleen/AbstractTest.java index c12381d8..20f2480b 100755 --- a/gateleen-test/src/test/java/org/swisspush/gateleen/AbstractTest.java +++ b/gateleen-test/src/test/java/org/swisspush/gateleen/AbstractTest.java @@ -247,7 +247,7 @@ public static void setupBeforeClass(TestContext context) { RunConfig.with() .cacheHandler(cacheHandler) .corsHandler(new CORSHandler()) - .deltaHandler(new DeltaHandler(redisProvider, selfClient, ruleProvider)) + .deltaHandler(new DeltaHandler(vertx, redisProvider, selfClient, ruleProvider, loggingResourceManager, logAppenderRepository)) .expansionHandler(new ExpansionHandler(vertx, storage, selfClient, props, ROOT, RULES_ROOT)) .hookHandler(hookHandler) .qosHandler(qosHandler) From 9c94da693c95a957cd05e561680dd79651677819 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Weber?= Date: Thu, 6 Jun 2024 16:52:33 +0200 Subject: [PATCH 2/2] #585 Some code cleanup --- .../java/org/swisspush/gateleen/delta/DeltaHandler.java | 8 ++++---- .../java/org/swisspush/gateleen/hook/ListenerTest.java | 5 ++--- .../test/java/org/swisspush/gateleen/queue/QueueTest.java | 4 ++-- 3 files changed, 8 insertions(+), 9 deletions(-) diff --git a/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java b/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java index 2260d34a..3cff33d9 100755 --- a/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java +++ b/gateleen-delta/src/main/java/org/swisspush/gateleen/delta/DeltaHandler.java @@ -61,9 +61,9 @@ public class DeltaHandler implements RuleProvider.RuleChangesObserver { private RuleProvider ruleProvider; - private Vertx vertx; - private LoggingResourceManager loggingResourceManager; - private LogAppenderRepository logAppenderRepository; + private final Vertx vertx; + private final LoggingResourceManager loggingResourceManager; + private final LogAppenderRepository logAppenderRepository; private RuleFeaturesProvider ruleFeaturesProvider = new RuleFeaturesProvider(new ArrayList<>()); public DeltaHandler(Vertx vertx, RedisProvider redisProvider, HttpClient httpClient, RuleProvider ruleProvider, @@ -349,7 +349,7 @@ private void handleCollectionGET(final HttpServerRequest request, final String u log.trace("DeltaHandler: deltaResourceKeys for targetUri ({}): {}", targetUri, deltaResourceKeys); } - if (deltaResourceKeys.size() > 0) { + if (!deltaResourceKeys.isEmpty()) { if (log.isTraceEnabled()) { log.trace("DeltaHandler: targetUri ({}) using mget command.", targetUri); } diff --git a/gateleen-test/src/test/java/org/swisspush/gateleen/hook/ListenerTest.java b/gateleen-test/src/test/java/org/swisspush/gateleen/hook/ListenerTest.java index 4a858aab..4282fe13 100755 --- a/gateleen-test/src/test/java/org/swisspush/gateleen/hook/ListenerTest.java +++ b/gateleen-test/src/test/java/org/swisspush/gateleen/hook/ListenerTest.java @@ -3,7 +3,6 @@ import com.github.tomakehurst.wiremock.client.WireMock; import com.github.tomakehurst.wiremock.junit.WireMockRule; import com.google.common.collect.ImmutableMap; -import org.awaitility.Awaitility; import io.restassured.RestAssured; import io.restassured.http.Header; import io.restassured.http.Headers; @@ -11,7 +10,7 @@ import io.vertx.ext.unit.Async; import io.vertx.ext.unit.TestContext; import io.vertx.ext.unit.junit.VertxUnitRunner; -import org.junit.Ignore; +import org.awaitility.Awaitility; import org.junit.Rule; import org.junit.Test; import org.junit.runner.RunWith; @@ -24,8 +23,8 @@ import static com.github.tomakehurst.wiremock.client.WireMock.aResponse; import static com.github.tomakehurst.wiremock.stubbing.Scenario.STARTED; -import static org.awaitility.Awaitility.await; import static io.restassured.RestAssured.*; +import static org.awaitility.Awaitility.await; import static org.awaitility.Durations.FIVE_SECONDS; import static org.awaitility.Durations.TEN_SECONDS; import static org.hamcrest.CoreMatchers.*; diff --git a/gateleen-test/src/test/java/org/swisspush/gateleen/queue/QueueTest.java b/gateleen-test/src/test/java/org/swisspush/gateleen/queue/QueueTest.java index 6113621b..cecb3477 100644 --- a/gateleen-test/src/test/java/org/swisspush/gateleen/queue/QueueTest.java +++ b/gateleen-test/src/test/java/org/swisspush/gateleen/queue/QueueTest.java @@ -14,8 +14,8 @@ import static org.awaitility.Awaitility.await; import static io.restassured.RestAssured.*; -import static junit.framework.Assert.assertFalse; -import static junit.framework.Assert.assertTrue; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; import static org.awaitility.Durations.*; import static org.hamcrest.CoreMatchers.*;