From 95e250d4bd10e102b71efcf230bf4668c8c9e391 Mon Sep 17 00:00:00 2001
From: Sam Brannen <sam@sambrannen.com>
Date: Sat, 25 Nov 2023 17:56:33 +0100
Subject: [PATCH] Log test aborted exceptions at INFO level in the TestContext
 framework

Prior to this commit, any time an aborted/skipped exception was thrown
by a TestExecutionListener, the TestContextManager unconditionally
logged the exception at WARN level -- or ERROR level for
prepareTestInstance() callbacks.

Regarding the latter, an aborted/skipped exception is certainly not an
ERROR, and in general the associated log output is very verbose
(including a stack trace) and not something the user should be warned
about it.

To improve the user experience, this commit revises TestContextManager
so that it logs such exceptions at INFO level.

Specifically, the following types of exceptions are considered
aborted/skipped exceptions.

- JUnit Jupiter: org.opentest4j.TestAbortedException
- JUnit 4 org.junit.AssumptionViolatedException
- TestNG: org.testng.SkipException

Closes gh-31479
---
 .../test/context/TestContextManager.java      | 67 +++++++++++++++++--
 1 file changed, 63 insertions(+), 4 deletions(-)

diff --git a/spring-test/src/main/java/org/springframework/test/context/TestContextManager.java b/spring-test/src/main/java/org/springframework/test/context/TestContextManager.java
index db62ee8700..6cd0480059 100644
--- a/spring-test/src/main/java/org/springframework/test/context/TestContextManager.java
+++ b/spring-test/src/main/java/org/springframework/test/context/TestContextManager.java
@@ -20,7 +20,9 @@ import java.lang.reflect.Constructor;
 import java.lang.reflect.Method;
 import java.util.ArrayList;
 import java.util.Collections;
+import java.util.LinkedHashSet;
 import java.util.List;
+import java.util.Set;
 
 import org.apache.commons.logging.Log;
 import org.apache.commons.logging.LogFactory;
@@ -90,6 +92,17 @@ public class TestContextManager {
 
 	private static final Log logger = LogFactory.getLog(TestContextManager.class);
 
+	private static final Set<Class<? extends Throwable>> skippedExceptionTypes = new LinkedHashSet<>(4);
+
+	static {
+		// JUnit Jupiter
+		loadSkippedExceptionType("org.opentest4j.TestAbortedException");
+		// JUnit 4
+		loadSkippedExceptionType("org.junit.AssumptionViolatedException");
+		// TestNG
+		loadSkippedExceptionType("org.testng.SkipException");
+	}
+
 	private final TestContext testContext;
 
 	private final ThreadLocal<TestContext> testContextHolder;
@@ -247,11 +260,19 @@ public class TestContextManager {
 					testExecutionListener.prepareTestInstance(getTestContext());
 				}
 				catch (Throwable ex) {
-					if (logger.isErrorEnabled()) {
+					if (isSkippedException(ex)) {
+						if (logger.isInfoEnabled()) {
+							logger.info("""
+									Caught exception while allowing TestExecutionListener [%s] to \
+									prepare test instance [%s]"""
+										.formatted(typeName(testExecutionListener), testInstance), ex);
+						}
+					}
+					else if (logger.isErrorEnabled()) {
 						logger.error("""
 							Caught exception while allowing TestExecutionListener [%s] to \
 							prepare test instance [%s]"""
-							.formatted(typeName(testExecutionListener), testInstance), ex);
+								.formatted(typeName(testExecutionListener), testInstance), ex);
 					}
 					ReflectionUtils.rethrowException(ex);
 				}
@@ -570,7 +591,15 @@ public class TestContextManager {
 	private void logException(
 			Throwable ex, String callbackName, TestExecutionListener testExecutionListener, Class<?> testClass) {
 
-		if (logger.isWarnEnabled()) {
+		if (isSkippedException(ex)) {
+			if (logger.isInfoEnabled()) {
+				logger.info("""
+						Caught exception while invoking '%s' callback on TestExecutionListener [%s] \
+						for test class [%s]"""
+							.formatted(callbackName, typeName(testExecutionListener), typeName(testClass)), ex);
+			}
+		}
+		else if (logger.isWarnEnabled()) {
 			logger.warn("""
 					Caught exception while invoking '%s' callback on TestExecutionListener [%s] \
 					for test class [%s]"""
@@ -581,7 +610,15 @@ public class TestContextManager {
 	private void logException(Throwable ex, String callbackName, TestExecutionListener testExecutionListener,
 			Object testInstance, Method testMethod) {
 
-		if (logger.isWarnEnabled()) {
+		if (isSkippedException(ex)) {
+			if (logger.isInfoEnabled()) {
+				logger.info("""
+						Caught exception while invoking '%s' callback on TestExecutionListener [%s] for \
+						test method [%s] and test instance [%s]"""
+							.formatted(callbackName, typeName(testExecutionListener), testMethod, testInstance), ex);
+			}
+		}
+		else if (logger.isWarnEnabled()) {
 			logger.warn("""
 					Caught exception while invoking '%s' callback on TestExecutionListener [%s] for \
 					test method [%s] and test instance [%s]"""
@@ -626,4 +663,26 @@ public class TestContextManager {
 		return obj.getClass().getName();
 	}
 
+	@SuppressWarnings("unchecked")
+	@Nullable
+	private static void loadSkippedExceptionType(String name) {
+		try {
+			Class<? extends Throwable> exceptionType = (Class<? extends Throwable>)
+					ClassUtils.forName(name, TestContextManager.class.getClassLoader());
+			skippedExceptionTypes.add(exceptionType);
+		}
+		catch (ClassNotFoundException | LinkageError ex) {
+			// ignore
+		}
+	}
+
+	private static boolean isSkippedException(Throwable ex) {
+		for (Class<? extends Throwable> skippedExceptionType : skippedExceptionTypes) {
+			if (skippedExceptionType.isInstance(ex)) {
+				return true;
+			}
+		}
+		return false;
+	}
+
 }