Merge branch 'hotfix-1.10.x' into hotfix-2.0.x

gentics · Feb 28, 2024 · 8419120 · 8419120
2 parents 8c49f6c + a7ed904
commit 8419120
Show file tree

Hide file tree

Showing 6 changed files with 149 additions and 90 deletions.
diff --git a/LTS-CHANGELOG.adoc b/LTS-CHANGELOG.adoc
@@ -17,6 +17,14 @@ include::content/docs/variables.adoc-include[]
 The LTS changelog lists releases which are only accessible via a commercial subscription.
 All fixes and changes in LTS releases will be released the next minor release. Changes from LTS 1.4.x will be included in release 1.5.0.
 
+[[v1.10.28]]
+== 1.10.28 (27.02.2024)
+
+icon:check[] GraphQL: In cases of long running GraphQL requests, some other GraphQL requests were queued and executed after the long running request, even if enough workers were still
+available. The behaviour has been changed, so that GraphQL requests will only be queued, if all workers are currently busy.
+
+icon:check[] Cache: The permission cache has been fixed to always return copies of the actually cached entries.
+
 [[v1.10.27]]
 == 1.10.27 (21.02.2024)
 

diff --git a/changelog/src/changelog/entries/2024/02/7698.SUP-16373.bugfix b/changelog/src/changelog/entries/2024/02/7698.SUP-16373.bugfix
@@ -0,0 +1,2 @@
+GraphQL: In cases of long running GraphQL requests, some other GraphQL requests were queued and executed after the long running request, even if enough workers were still
+available. The behaviour has been changed, so that GraphQL requests will only be queued, if all workers are currently busy.
diff --git a/changelog/src/changelog/entries/2024/02/7699.SUP-16383.bugfix b/changelog/src/changelog/entries/2024/02/7699.SUP-16383.bugfix
@@ -0,0 +1 @@
+Cache: The permission cache has been fixed to always return copies of the actually cached entries.
diff --git a/core/src/main/java/com/gentics/mesh/cache/PermissionCacheImpl.java b/core/src/main/java/com/gentics/mesh/cache/PermissionCacheImpl.java
@@ -9,6 +9,7 @@
 import java.util.EnumSet;
 import java.util.HashMap;
 import java.util.Map;
+import java.util.function.Function;
 
 import javax.inject.Inject;
 import javax.inject.Singleton;
@@ -73,7 +74,8 @@ private static EventAwareCache<String, EnumSet<InternalPermission>> createCache(
 
 	@Override
 	public Boolean hasPermission(Object userId, InternalPermission permission, Object elementId) {
-		EnumSet<InternalPermission> cachedPermissions = get(userId, elementId);
+		// note: we access the cache instance directly here to avoid cloning of the returned entry (which we will not mutate)
+		EnumSet<InternalPermission> cachedPermissions = cache.get(createCacheKey(userId, elementId));
 		if (cachedPermissions != null) {
 			return cachedPermissions.contains(permission);
 		} else {
@@ -123,6 +125,28 @@ public EnumSet<InternalPermission> get(Object userId, Object elementId) {
 		return get(createCacheKey(userId, elementId));
 	}
 
+	@Override
+	public EnumSet<InternalPermission> get(String key) {
+		EnumSet<InternalPermission> cached = super.get(key);
+		if (cached != null) {
+			// since the EnumSet is mutable, we return a clone of the instance
+			return EnumSet.copyOf(cached);
+		} else {
+			return null;
+		}
+	}
+
+	@Override
+	public EnumSet<InternalPermission> get(String key, Function<String, EnumSet<InternalPermission>> mappingFunction) {
+		EnumSet<InternalPermission> cached = super.get(key, mappingFunction);
+		if (cached != null) {
+			// since the EnumSet is mutable, we return a clone of the instance
+			return EnumSet.copyOf(cached);
+		} else {
+			return null;
+		}
+	}
+
 	@Override
 	public void store(Object userId, EnumSet<InternalPermission> permission, Object elementId) {
 		// deduplicate the permission EnumSet and put it into the cache

diff --git a/tests/tests-core/src/main/java/com/gentics/mesh/core/perm/PermissionCacheTest.java b/tests/tests-core/src/main/java/com/gentics/mesh/core/perm/PermissionCacheTest.java
@@ -3,14 +3,15 @@
 import static com.gentics.mesh.mock.Mocks.getMockedInternalActionContext;
 import static org.assertj.core.api.Assertions.assertThat;
 
-import java.util.Arrays;
-import java.util.Collections;
-import java.util.HashSet;
+import java.util.EnumSet;
 import java.util.Set;
+import java.util.UUID;
 
 import org.junit.Before;
 import org.junit.Test;
 
+import com.gentics.mesh.cache.PermissionCache;
+import com.gentics.mesh.cache.PermissionCacheImpl;
 import com.gentics.mesh.context.InternalActionContext;
 import com.gentics.mesh.context.impl.DummyBulkActionContext;
 import com.gentics.mesh.context.impl.DummyEventQueueBatch;
@@ -23,6 +24,7 @@
 import com.gentics.mesh.test.MeshTestSetting;
 import com.gentics.mesh.test.TestSize;
 import com.gentics.mesh.test.context.AbstractMeshTest;
+import com.gentics.mesh.util.UUIDUtil;
 
 /**
  * Test cases for usage and clearing of PermissionCache
@@ -221,6 +223,34 @@ public void testRevokeAdmin() {
 		assertPermissions("revoking admin flag");
 	}
 
+	/**
+	 * Test that mutations of permission entries fetched from the cache will not change the cached entry itself
+	 */
+	@Test
+	public void testMutateCachedEntry() {
+		UUID userId = UUIDUtil.toJavaUuid(UUIDUtil.randomUUID());
+		UUID elementId = UUIDUtil.toJavaUuid(UUIDUtil.randomUUID());
+
+		// store permission in the cache
+		db().tx(tx -> {
+			EnumSet<InternalPermission> cached = EnumSet.of(InternalPermission.CREATE_PERM, InternalPermission.UPDATE_PERM);
+			tx.permissionCache().store(userId, cached, elementId);
+		});
+
+		// get stored permission and mutate
+		EnumSet<InternalPermission> cached = db().tx(tx -> {
+			return tx.permissionCache().get(userId, elementId);
+		});
+		assertThat(cached).as("Cached permissions").isNotNull().containsOnly(InternalPermission.CREATE_PERM, InternalPermission.UPDATE_PERM);
+		cached.add(InternalPermission.READ_PERM);
+
+		// get again
+		cached =  db().tx(tx -> {
+			return tx.permissionCache().get(userId, elementId);
+		});
+		assertThat(cached).as("Cached permissions").isNotNull().containsOnly(InternalPermission.CREATE_PERM, InternalPermission.UPDATE_PERM);
+	}
+
 	/**
 	 * Get the size of the permission cache
 	 * @return cache size

diff --git a/verticles/graphql/src/main/java/com/gentics/mesh/graphql/GraphQLHandler.java b/verticles/graphql/src/main/java/com/gentics/mesh/graphql/GraphQLHandler.java
@@ -83,99 +83,93 @@ public GraphQLHandler(MetricsService metrics, MeshOptions options, QueryTypeProv
 	 *            GraphQL query
 	 */
 	public void handleQuery(GraphQLContext gc, String body) {
-		vertx.rxExecuteBlocking(promise -> {
-			Timer.Sample sample = Timer.start();
-			AtomicReference<String> loggableQuery = new AtomicReference<>();
-			AtomicReference<Map<String, Object>> loggableVariables = new AtomicReference<>();
-			try {
-				db.tx(tx -> {
-					JsonObject queryJson = new JsonObject(body);
-					// extract query body and variables from the sent body
-					String query = queryJson.getString("query");
-					Map<String, Object> variables = extractVariables(queryJson);
-					// store for possibly logging it later
-					loggableQuery.set(query);
-					loggableVariables.set(variables);
-					GraphQL graphQL = newGraphQL(typeProvider.getRootSchema(gc)).instrumentation(new DataLoaderDispatcherInstrumentation()).build();
-
-					DataLoaderRegistry dataLoaderRegistry = new DataLoaderRegistry();
-					DataLoaderOptions dlOptions = DataLoaderOptions.newOptions().setBatchLoaderContextProvider(() -> gc);
-					// TODO this is inefficient, but otherwise we can't easily tell if a filter is native ready without parsing each of it ahead of time.
-					dlOptions.setCachingEnabled(options.getNativeQueryFiltering() == NativeQueryFiltering.NEVER);
-					dataLoaderRegistry.register(NodeDataLoader.CONTENT_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.CONTENT_LOADER, dlOptions));
-					dataLoaderRegistry.register(NodeDataLoader.CHILDREN_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.CHILDREN_LOADER, dlOptions));
-					dataLoaderRegistry.register(NodeDataLoader.PATH_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.PATH_LOADER, dlOptions));
-					dataLoaderRegistry.register(NodeDataLoader.PARENT_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.PARENT_LOADER, dlOptions));
-					dataLoaderRegistry.register(NodeDataLoader.REFERENCED_BY_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.REFERENCED_BY_LOADER, dlOptions));
-					dataLoaderRegistry.register(NodeDataLoader.BREADCRUMB_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.BREADCRUMB_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.LINK_REPLACER_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().LINK_REPLACER_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.BOOLEAN_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().BOOLEAN_LIST_VALUE_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.DATE_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().DATE_LIST_VALUE_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.NUMBER_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().NUMBER_LIST_VALUE_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.HTML_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().HTML_LIST_VALUE_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.STRING_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().STRING_LIST_VALUE_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.MICRONODE_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().MICRONODE_LIST_VALUE_LOADER, dlOptions));
-					dataLoaderRegistry.register(FieldDefinitionProvider.MICRONODE_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().MICRONODE_LOADER, dlOptions));
-
-					ExecutionInput executionInput = ExecutionInput
-						.newExecutionInput()
-						.dataLoaderRegistry(dataLoaderRegistry)
-						.query(query)
-						.context(gc)
-						.variables(variables)
-						.build();
-					try {
-						// Implementation Note: GraphQL is implemented synchronously (no implemented datafetcher returns a CompletableFuture, which is not yet completed)
-						// Nonetheless, we see sometimes that the CompletableFuture is not completed (and never will be), when GraphQL joins it, which leads to endlessly
-						// blocked worker threads.
-						// Therefore, we use the "async approach" for calling GraphQL and wait for the result with a timeout.
-						ExecutionResult result = graphQL.executeAsync(executionInput)
-								.get(options.getGraphQLOptions().getAsyncWaitTimeout(), TimeUnit.MILLISECONDS);
-						List<GraphQLError> errors = result.getErrors();
-						JsonObject response = new JsonObject();
-						if (!errors.isEmpty()) {
-							addErrors(errors, response);
-							if (log.isDebugEnabled()) {
-								log.debug("Encountered {" + errors.size() + "} errors while executing query {" + query + "}");
-								for (GraphQLError error : errors) {
-									String loc = "unknown location";
-									if (error.getLocations() != null) {
-										loc = error.getLocations().stream().map(Object::toString).collect(Collectors.joining(","));
-									}
-									log.debug("Error: " + error.getErrorType() + ":" + error.getMessage() + ":" + loc);
+		Timer.Sample sample = Timer.start();
+		AtomicReference<String> loggableQuery = new AtomicReference<>();
+		AtomicReference<Map<String, Object>> loggableVariables = new AtomicReference<>();
+		try {
+			db.tx(tx -> {
+				JsonObject queryJson = new JsonObject(body);
+				// extract query body and variables from the sent body
+				String query = queryJson.getString("query");
+				Map<String, Object> variables = extractVariables(queryJson);
+				// store for possibly logging it later
+				loggableQuery.set(query);
+				loggableVariables.set(variables);
+				GraphQL graphQL = newGraphQL(typeProvider.getRootSchema(gc)).instrumentation(new DataLoaderDispatcherInstrumentation()).build();
+
+				DataLoaderRegistry dataLoaderRegistry = new DataLoaderRegistry();
+				DataLoaderOptions dlOptions = DataLoaderOptions.newOptions().setBatchLoaderContextProvider(() -> gc);
+				// TODO this is inefficient, but otherwise we can't easily tell if a filter is native ready without parsing each of it ahead of time.
+				dlOptions.setCachingEnabled(options.getNativeQueryFiltering() == NativeQueryFiltering.NEVER);
+				dataLoaderRegistry.register(NodeDataLoader.CONTENT_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.CONTENT_LOADER, dlOptions));
+				dataLoaderRegistry.register(NodeDataLoader.CHILDREN_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.CHILDREN_LOADER, dlOptions));
+				dataLoaderRegistry.register(NodeDataLoader.PATH_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.PATH_LOADER, dlOptions));
+				dataLoaderRegistry.register(NodeDataLoader.PARENT_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.PARENT_LOADER, dlOptions));
+				dataLoaderRegistry.register(NodeDataLoader.REFERENCED_BY_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.REFERENCED_BY_LOADER, dlOptions));
+				dataLoaderRegistry.register(NodeDataLoader.BREADCRUMB_LOADER_KEY, DataLoader.newDataLoader(NodeDataLoader.BREADCRUMB_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.LINK_REPLACER_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().LINK_REPLACER_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.BOOLEAN_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().BOOLEAN_LIST_VALUE_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.DATE_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().DATE_LIST_VALUE_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.NUMBER_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().NUMBER_LIST_VALUE_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.HTML_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().HTML_LIST_VALUE_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.STRING_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().STRING_LIST_VALUE_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.MICRONODE_LIST_VALUES_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().MICRONODE_LIST_VALUE_LOADER, dlOptions));
+				dataLoaderRegistry.register(FieldDefinitionProvider.MICRONODE_DATA_LOADER_KEY, DataLoader.newDataLoader(typeProvider.getFieldDefProvider().MICRONODE_LOADER, dlOptions));
+
+				ExecutionInput executionInput = ExecutionInput
+					.newExecutionInput()
+					.dataLoaderRegistry(dataLoaderRegistry)
+					.query(query)
+					.context(gc)
+					.variables(variables)
+					.build();
+				try {
+					// Implementation Note: GraphQL is implemented synchronously (no implemented datafetcher returns a CompletableFuture, which is not yet completed)
+					// Nonetheless, we see sometimes that the CompletableFuture is not completed (and never will be), when GraphQL joins it, which leads to endlessly
+					// blocked worker threads.
+					// Therefore, we use the "async approach" for calling GraphQL and wait for the result with a timeout.
+					ExecutionResult result = graphQL.executeAsync(executionInput)
+							.get(options.getGraphQLOptions().getAsyncWaitTimeout(), TimeUnit.MILLISECONDS);
+					List<GraphQLError> errors = result.getErrors();
+					JsonObject response = new JsonObject();
+					if (!errors.isEmpty()) {
+						addErrors(errors, response);
+						if (log.isDebugEnabled()) {
+							log.debug("Encountered {" + errors.size() + "} errors while executing query {" + query + "}");
+							for (GraphQLError error : errors) {
+								String loc = "unknown location";
+								if (error.getLocations() != null) {
+									loc = error.getLocations().stream().map(Object::toString).collect(Collectors.joining(","));
 								}
+								log.debug("Error: " + error.getErrorType() + ":" + error.getMessage() + ":" + loc);
 							}
 						}
-						if (result.getData() != null) {
-							Map<String, Object> data = result.getData();
-							response.put("data", new JsonObject(data));
-						}
-						gc.send(response.encodePrettily(), OK);
-						promise.complete();
-					} catch (TimeoutException | InterruptedException | ExecutionException e) {
-						// If an error happens while "waiting" for the result, we log the GraphQL query here.
-						log.error("GraphQL query failed after {} ms with {}:\n{}\nvariables: {}",
-								options.getGraphQLOptions().getAsyncWaitTimeout(), e.getClass().getSimpleName(), loggableQuery.get(),
-								loggableVariables.get());
-						gc.fail(e);
-						promise.fail(e);
 					}
-				});
-			} catch (Exception e) {
-				promise.fail(e);
-			} finally {
-				long duration = sample.stop(graphQlTimer);
-				Long slowThreshold = options.getGraphQLOptions().getSlowThreshold();
-				if (loggableQuery.get() != null && slowThreshold != null && slowThreshold.longValue() > 0) {
-					long durationMs = TimeUnit.MILLISECONDS.convert(duration, TimeUnit.NANOSECONDS);
-					if (durationMs > slowThreshold) {
-						slowQueryLog.warn("GraphQL Query took {} ms:\n{}\nvariables: {}", durationMs, loggableQuery.get(), loggableVariables.get());
+					if (result.getData() != null) {
+						Map<String, Object> data = result.getData();
+						response.put("data", new JsonObject(data));
 					}
+					gc.send(response.encodePrettily(), OK);
+				} catch (TimeoutException | InterruptedException | ExecutionException e) {
+					// If an error happens while "waiting" for the result, we log the GraphQL query here.
+					log.error("GraphQL query failed after {} ms with {}:\n{}\nvariables: {}",
+							options.getGraphQLOptions().getAsyncWaitTimeout(), e.getClass().getSimpleName(), loggableQuery.get(),
+							loggableVariables.get());
+					gc.fail(e);
+				}
+			});
+		} catch (Exception e) {
+			gc.fail(e);
+		} finally {
+			long duration = sample.stop(graphQlTimer);
+			Long slowThreshold = options.getGraphQLOptions().getSlowThreshold();
+			if (loggableQuery.get() != null && slowThreshold != null && slowThreshold.longValue() > 0) {
+				long durationMs = TimeUnit.MILLISECONDS.convert(duration, TimeUnit.NANOSECONDS);
+				if (durationMs > slowThreshold) {
+					slowQueryLog.warn("GraphQL Query took {} ms:\n{}\nvariables: {}", durationMs, loggableQuery.get(), loggableVariables.get());
 				}
 			}
-		})
-		.doOnError(gc::fail)
-		.subscribe();
+		}
 	}
 
 	/**