Improve logging of controller method mappings

Author: rstoyanchev

spring-graphql/src/main/java/org/springframework/graphql/data/federation/FederationSchemaFactory.java

@@ -22,6 +22,7 @@
 import java.util.Map;
 import java.util.concurrent.CompletionStage;
 import java.util.function.BiFunction;
+import java.util.stream.Collectors;
 
 import com.apollographql.federation.graphqljava.Federation;
 import com.apollographql.federation.graphqljava.SchemaTransformer;
@@ -98,6 +99,13 @@ public void afterPropertiesSet() {
 		if (this.typeResolver == null) {
 			this.typeResolver = new ClassNameTypeResolver();
 		}
+
+		if (logger.isTraceEnabled()) {
+			String formatted = this.handlerMethods.entrySet().stream()
+					.map((entry) -> entry.getKey() + " -> " + entry.getValue().getShortLogMessage())
+					.collect(Collectors.joining("\n", "\n", "\n"));
+			logger.trace("@EntityMapping registrations:" + formatted);
+		}
 	}
 
 	@Override

spring-graphql/src/main/java/org/springframework/graphql/data/method/annotation/support/AnnotatedControllerConfigurer.java

@@ -257,9 +257,13 @@ public void configure(RuntimeWiring.Builder runtimeWiringBuilder) {
 		allInfos.forEach((info) -> registerDataFetcher(info, runtimeWiringBuilder));
 
 		RuntimeWiring wiring = runtimeWiringBuilder.build();
-		subTypeInfos = this.interfaceMappingHelper.filterExistingMappings(subTypeInfos, wiring.getDataFetchers());
+		subTypeInfos = this.interfaceMappingHelper.removeExplicitMappings(subTypeInfos, wiring.getDataFetchers());
 
 		subTypeInfos.forEach((info) -> registerDataFetcher(info, runtimeWiringBuilder));
+
+		if (logger.isTraceEnabled()) {
+			logger.trace("Controller method registrations:" + formatRegistrations(runtimeWiringBuilder));
+		}
 	}
 
 	@Override
@@ -403,6 +407,16 @@ private DataFetcher<Object> registerBatchLoader(DataFetcherMappingInfo info) {
 						"Mono<Map<K, V>>, Map<K, V>, Flux<V>, or Collection<V>: " + handlerMethod);
 	}
 
+	@SuppressWarnings("rawtypes")
+	protected static String formatRegistrations(RuntimeWiring.Builder wiringBuilder) {
+		return wiringBuilder.build().getDataFetchers().entrySet().stream()
+				.map((typeEntry) -> typeEntry.getKey() + ":\n" +
+						typeEntry.getValue().entrySet().stream()
+								.map((fieldEntry) -> fieldEntry.getKey() + " -> " + fieldEntry.getValue())
+								.collect(Collectors.joining("\n\t", "\t", "")))
+				.collect(Collectors.joining("\n", "\n", "\n"));
+	}
+
 	/**
 	 * Alternative to {@link #configure(RuntimeWiring.Builder)} that registers
 	 * data fetchers in a {@link GraphQLCodeRegistry.Builder}. This could be
@@ -587,6 +601,11 @@ public Object get(DataFetchingEnvironment env) {
 			Assert.state(dataLoader != null, "No DataLoader for key '" + this.dataLoaderKey + "'");
 			return dataLoader.load(env.getSource());
 		}
+
+		@Override
+		public String toString() {
+			return getDescription();
+		}
 	}
 
 
@@ -597,6 +616,9 @@ private static final class InterfaceMappingHelper {
 
 		private final MultiValueMap<String, String> interfaceMappings = new LinkedMultiValueMap<>();
 
+		/**
+		 * Extract information interface implementation types.
+		 */
 		void setTypeDefinitionRegistry(TypeDefinitionRegistry registry) {
 			for (TypeDefinition<?> definition : registry.types().values()) {
 				if (definition instanceof ObjectTypeDefinition objectDefinition) {
@@ -607,6 +629,10 @@ void setTypeDefinitionRegistry(TypeDefinitionRegistry registry) {
 			}
 		}
 
+		/**
+		 * Remove mappings to interface fields, and return mappings for the same
+		 * fields in all implementing types.
+		 */
 		Set<DataFetcherMappingInfo> removeInterfaceMappings(Set<DataFetcherMappingInfo> infos) {
 			Set<DataFetcherMappingInfo> subTypeMappings = new LinkedHashSet<>();
 			Iterator<DataFetcherMappingInfo> it = infos.iterator();
@@ -623,8 +649,11 @@ Set<DataFetcherMappingInfo> removeInterfaceMappings(Set<DataFetcherMappingInfo>
 			return subTypeMappings;
 		}
 
+		/**
+		 * Remove mappings that are covered by explicit {@link DataFetcher} registrations.
+		 */
 		@SuppressWarnings("rawtypes")
-		Set<DataFetcherMappingInfo> filterExistingMappings(
+		Set<DataFetcherMappingInfo> removeExplicitMappings(
 				Set<DataFetcherMappingInfo> infos, Map<String, Map<String, DataFetcher>> dataFetchers) {
 
 			return infos.stream()

spring-graphql/src/main/java/org/springframework/graphql/data/method/annotation/support/AnnotatedControllerDetectionSupport.java

@@ -17,8 +17,6 @@
 package org.springframework.graphql.data.method.annotation.support;
 
 import java.lang.reflect.Method;
-import java.lang.reflect.Type;
-import java.util.Arrays;
 import java.util.Collection;
 import java.util.Collections;
 import java.util.LinkedHashSet;
@@ -28,7 +26,6 @@
 import java.util.concurrent.Callable;
 import java.util.concurrent.Executor;
 import java.util.function.Predicate;
-import java.util.stream.Collectors;
 
 import graphql.schema.DataFetcher;
 import org.apache.commons.logging.Log;
@@ -258,13 +255,12 @@ protected Set<M> detectHandlerMethods() {
 				continue;
 			}
 			Class<?> beanClass = context.getType(beanName);
-			findHandlerMethods(beanName, beanClass).forEach((info) -> registerHandlerMethod(info, results));
+			findHandlerMethods(beanName, beanClass).forEach((info) -> addHandlerMethod(info, results));
 		}
+
 		return results;
 	}
 
-	protected abstract HandlerMethod getHandlerMethod(M mappingInfo);
-
 	private Collection<M> findHandlerMethods(Object handler, @Nullable Class<?> handlerClass) {
 		if (handlerClass == null) {
 			return Collections.emptyList();
@@ -274,34 +270,20 @@ private Collection<M> findHandlerMethods(Object handler, @Nullable Class<?> hand
 		Map<Method, M> map = MethodIntrospector.selectMethods(
 				userClass, (Method method) -> getMappingInfo(method, handler, userClass));
 
-		Collection<M> mappingInfos = map.values();
-
-		if (this.logger.isTraceEnabled() && !mappingInfos.isEmpty()) {
-			this.logger.trace(formatMappings(userClass, mappingInfos));
-		}
-
-		return mappingInfos;
+		return map.values();
 	}
 
 	@Nullable
 	protected abstract M getMappingInfo(Method method, Object handler, Class<?> handlerType);
 
-	private String formatMappings(Class<?> handlerType, Collection<M> infos) {
-		String formattedType = Arrays.stream(ClassUtils.getPackageName(handlerType).split("\\."))
-				.map((p) -> p.substring(0, 1))
-				.collect(Collectors.joining(".", "", "." + handlerType.getSimpleName()));
-		return infos.stream()
-				.map((info) -> {
-					Method method = getHandlerMethod(info).getMethod();
-					String methodParameters = Arrays.stream(method.getGenericParameterTypes())
-							.map(Type::getTypeName)
-							.collect(Collectors.joining(",", "(", ")"));
-					return info + methodParameters;
-				})
-				.collect(Collectors.joining("\n\t", "\n\t" + formattedType + ":" + "\n\t", ""));
+	protected HandlerMethod createHandlerMethod(Method originalMethod, Object handler, Class<?> handlerType) {
+		Method method = AopUtils.selectInvocableMethod(originalMethod, handlerType);
+		return (handler instanceof String beanName) ?
+				new HandlerMethod(beanName, obtainApplicationContext().getAutowireCapableBeanFactory(), method) :
+				new HandlerMethod(handler, method);
 	}
 
-	private void registerHandlerMethod(M info, Set<M> results) {
+	private void addHandlerMethod(M info, Set<M> results) {
 		Assert.state(this.exceptionResolver != null, "afterPropertiesSet not called");
 		HandlerMethod handlerMethod = getHandlerMethod(info);
 		M existing = results.stream().filter((o) -> o.equals(info)).findFirst().orElse(null);
@@ -315,12 +297,7 @@ private void registerHandlerMethod(M info, Set<M> results) {
 		this.exceptionResolver.registerController(handlerMethod.getBeanType());
 	}
 
-	protected HandlerMethod createHandlerMethod(Method originalMethod, Object handler, Class<?> handlerType) {
-		Method method = AopUtils.selectInvocableMethod(originalMethod, handlerType);
-		return (handler instanceof String beanName) ?
-				new HandlerMethod(beanName, obtainApplicationContext().getAutowireCapableBeanFactory(), method) :
-				new HandlerMethod(handler, method);
-	}
+	protected abstract HandlerMethod getHandlerMethod(M mappingInfo);
 
 	protected boolean shouldInvokeAsync(HandlerMethod handlerMethod) {
 		return (this.blockingMethodPredicate.test(handlerMethod) && this.executor != null &&