Introduce LoggingResultHandler in Spring MVC Test

sbrannen · sbrannen · commit 693dcba8679e · 2015-06-27T21:53:19.000+02:00
Prior to this commit, the Spring MVC Test framework only provided
support for printing debug information about the MvcResult to STDOUT.

This commit introduces support for logging `MvcResult` details at
`DEBUG` level via the Apache Commons Logging API. In addition, this
commit introduces additional `print(..)` variants for printing debug
information to custom output streams and writers.

Specifically, `MockMvcResultHandlers` has been augmented with the
following new static methods:

 - `log()`
 - `print(OutputStream)`
 - `print(Writer)`

Issue: SPR-13171
diff --git a/spring-test/src/main/java/org/springframework/test/web/servlet/result/MockMvcResultHandlers.java b/spring-test/src/main/java/org/springframework/test/web/servlet/result/MockMvcResultHandlers.java
@@ -16,6 +16,14 @@
 
 package org.springframework.test.web.servlet.result;
 
+import java.io.OutputStream;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.io.Writer;
+
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
+
 import org.springframework.test.web.servlet.MvcResult;
 import org.springframework.test.web.servlet.ResultHandler;
 import org.springframework.util.CollectionUtils;
@@ -32,35 +40,100 @@
  */
 public abstract class MockMvcResultHandlers {
 
+	private static final Log logger = LogFactory.getLog(MockMvcResultHandlers.class.getPackage().getName());
+
+
+	/**
+	 * Log {@link MvcResult} details as a {@code DEBUG} log message via
+	 * Apache Commons Logging using the log category
+	 * {@code org.springframework.test.web.servlet.result}.
+	 * @since 4.2
+	 * @see #print()
+	 * @see #print(OutputStream)
+	 * @see #print(Writer)
+	 */
+	public static ResultHandler log() {
+		return new LoggingResultHandler();
+	}
+
 	/**
 	 * Print {@link MvcResult} details to the "standard" output stream.
+	 * @see System#out
+	 * @see #print(OutputStream)
+	 * @see #print(Writer)
+	 * @see #log()
 	 */
 	public static ResultHandler print() {
-		return new ConsolePrintingResultHandler();
+		return print(System.out);
 	}
 
+	/**
+	 * Print {@link MvcResult} details to the supplied {@link OutputStream}.
+	 * @since 4.2
+	 * @see #print()
+	 * @see #print(Writer)
+	 * @see #log()
+	 */
+	public static ResultHandler print(OutputStream stream) {
+		return new PrintWriterPrintingResultHandler(new PrintWriter(stream, true));
+	}
 
 	/**
-	 * An {@link PrintingResultHandler} that writes to the "standard" output stream
+	 * Print {@link MvcResult} details to the supplied {@link Writer}.
+	 * @since 4.2
+	 * @see #print()
+	 * @see #print(OutputStream)
+	 * @see #log()
 	 */
-	private static class ConsolePrintingResultHandler extends PrintingResultHandler {
+	public static ResultHandler print(Writer writer) {
+		return new PrintWriterPrintingResultHandler(new PrintWriter(writer, true));
+	}
+
 
-		public ConsolePrintingResultHandler() {
+	/**
+	 * A {@link PrintingResultHandler} that writes to a {@link PrintWriter}.
+	 */
+	private static class PrintWriterPrintingResultHandler extends PrintingResultHandler {
+
+		PrintWriterPrintingResultHandler(final PrintWriter writer) {
 			super(new ResultValuePrinter() {
 				@Override
 				public void printHeading(String heading) {
-					System.out.println();
-					System.out.println(String.format("%s:", heading));
+					writer.println();
+					writer.println(String.format("%s:", heading));
 				}
 				@Override
 				public void printValue(String label, Object value) {
 					if (value != null && value.getClass().isArray()) {
 						value = CollectionUtils.arrayToList(value);
 					}
-					System.out.println(String.format("%17s = %s", label, value));
+					writer.println(String.format("%17s = %s", label, value));
 				}
 			});
 		}
 	}
 
+	/**
+	 * A {@link ResultHandler} that logs {@link MvcResult} details at
+	 * {@code DEBUG} level via Apache Commons Logging.
+	 *
+	 * <p>Delegates to a {@link PrintWriterPrintingResultHandler} for
+	 * building the log message.
+	 * @since 4.2
+	 */
+	private static class LoggingResultHandler implements ResultHandler {
+
+		private final StringWriter stringWriter = new StringWriter();
+
+		private final ResultHandler printingResultHandler = new PrintWriterPrintingResultHandler(
+			new PrintWriter(stringWriter, true));
+
+
+		@Override
+		public void handle(MvcResult result) throws Exception {
+			this.printingResultHandler.handle(result);
+			logger.debug("MvcResult details:\n" + this.stringWriter);
+		}
+	}
+
 }
diff --git a/spring-test/src/main/java/org/springframework/test/web/servlet/result/PrintingResultHandler.java b/spring-test/src/main/java/org/springframework/test/web/servlet/result/PrintingResultHandler.java
@@ -40,10 +40,13 @@
 import org.springframework.web.servlet.support.RequestContextUtils;
 
 /**
- * Result handler that prints {@link MvcResult} details to the "standard" output
- * stream.
- * <p>An instance of this class is typically accessed via
- * {@link MockMvcResultHandlers#print()}.
+ * Result handler that prints {@link MvcResult} details to a given output
+ * stream &mdash; for example: {@code System.out}, {@code System.err}, a
+ * custom {@code java.io.PrintWriter}, etc.
+ *
+ * <p>An instance of this class is typically accessed via one of the
+ * {@link MockMvcResultHandlers#print print} or {@link MockMvcResultHandlers#log log}
+ * methods in {@link MockMvcResultHandlers}.
  *
  * @author Rossen Stoyanchev
  * @author Sam Brannen
@@ -70,7 +73,7 @@ protected ResultValuePrinter getPrinter() {
 	}
 
 	/**
-	 * Print {@link MvcResult} details to the "standard" output stream.
+	 * Print {@link MvcResult} details.
 	 */
 	@Override
 	public final void handle(MvcResult result) throws Exception {
diff --git a/spring-test/src/test/java/org/springframework/test/web/servlet/result/PrintingResultHandlerTests.java b/spring-test/src/test/java/org/springframework/test/web/servlet/result/PrintingResultHandlerTests.java
@@ -42,10 +42,11 @@
 import static org.junit.Assert.*;
 
 /**
- * Tests for {@link PrintingResultHandler}.
+ * Unit tests for {@link PrintingResultHandler}.
  *
  * @author Rossen Stoyanchev
  * @author Sam Brannen
+ * @see org.springframework.test.web.servlet.samples.standalone.resulthandlers.PrintingResultHandlerSmokeTests
  */
 public class PrintingResultHandlerTests {
 
diff --git a/spring-test/src/test/java/org/springframework/test/web/servlet/samples/standalone/resulthandlers/PrintingResultHandlerSmokeTests.java b/spring-test/src/test/java/org/springframework/test/web/servlet/samples/standalone/resulthandlers/PrintingResultHandlerSmokeTests.java
@@ -16,13 +16,16 @@
 
 package org.springframework.test.web.servlet.samples.standalone.resulthandlers;
 
+import java.io.StringWriter;
+
 import javax.servlet.http.Cookie;
 import javax.servlet.http.HttpServletResponse;
 
 import org.junit.Ignore;
 import org.junit.Test;
 
 import org.springframework.stereotype.Controller;
+import org.springframework.test.web.servlet.result.PrintingResultHandler;
 import org.springframework.web.bind.annotation.RequestMapping;
 import org.springframework.web.bind.annotation.ResponseBody;
 
@@ -31,17 +34,38 @@
 import static org.springframework.test.web.servlet.setup.MockMvcBuilders.*;
 
 /**
- * Print debugging information about the executed request and response to System.out.
+ * Smoke test for {@link PrintingResultHandler}.
+ *
+ * <p>Prints debugging information about the executed request and response to
+ * various output streams.
+ *
+ * <p><strong>NOTE</strong>: this <em>smoke test</em> is not intended to be
+ * executed with the build. To run this test, comment out the {@code @Ignore}
+ * declaration and inspect the output manually.
  *
  * @author Rossen Stoyanchev
  * @author Sam Brannen
+ * @see org.springframework.test.web.servlet.result.PrintingResultHandlerTests
  */
 @Ignore("Not intended to be executed with the build. Comment out this line to inspect the output manually.")
-public class PrintingResultHandlerTests {
+public class PrintingResultHandlerSmokeTests {
 
 	@Test
 	public void testPrint() throws Exception {
-		standaloneSetup(new SimpleController()).build().perform(get("/")).andDo(print());
+		StringWriter writer = new StringWriter();
+
+		standaloneSetup(new SimpleController())
+			.build()
+			.perform(get("/"))
+			.andDo(log())
+			.andDo(print())
+			.andDo(print(System.err))
+			.andDo(print(writer))
+		;
+
+		System.out.println();
+		System.out.println("===============================================================");
+		System.out.println(writer.toString());
 	}
 
 
diff --git a/spring-test/src/test/resources/log4j.properties b/spring-test/src/test/resources/log4j.properties
@@ -3,28 +3,29 @@ log4j.appender.console.layout=org.apache.log4j.PatternLayout
 log4j.appender.console.layout.ConversionPattern=%d{HH:mm:ss,SSS} [%-5p] [%c] - %m%n
 
 log4j.appender.file=org.apache.log4j.FileAppender
-log4j.appender.file.file=build/spring-test.log
+log4j.appender.file.file=bin/spring-test.log
 log4j.appender.file.layout=org.apache.log4j.PatternLayout
 log4j.appender.file.layout.ConversionPattern=%d{HH:mm:ss,SSS} [%c] - %m%n
 
 log4j.rootCategory=ERROR, console, file
 
 log4j.logger.org.springframework.beans=WARN
 
+log4j.logger.org.springframework.test.context=WARN
 log4j.logger.org.springframework.test.context.TestContext=WARN
 log4j.logger.org.springframework.test.context.TestContextManager=WARN
 log4j.logger.org.springframework.test.context.ContextLoaderUtils=WARN
-log4j.logger.org.springframework.test.context.transaction.TransactionalTestExecutionListener=WARN
-log4j.logger.org.springframework.test.context.web=WARN
-log4j.logger.org.springframework.test.context=WARN
 log4j.logger.org.springframework.test.context.cache=WARN
-
 log4j.logger.org.springframework.test.context.junit4.rules=WARN
+log4j.logger.org.springframework.test.context.transaction.TransactionalTestExecutionListener=WARN
+log4j.logger.org.springframework.test.context.web=WARN
 
 #log4j.logger.org.springframework.test.context.support=INFO
 #log4j.logger.org.springframework.test.context.support.DelegatingSmartContextLoader=INFO
 #log4j.logger.org.springframework.test.context.support.AbstractGenericContextLoader=INFO
 #log4j.logger.org.springframework.test.context.support.AnnotationConfigContextLoader=INFO
 
+log4j.logger.org.springframework.test.web.servlet.result=DEBUG
+
 #log4j.logger.org.springframework.test=TRACE
 
diff --git a/src/asciidoc/whats-new.adoc b/src/asciidoc/whats-new.adoc
@@ -554,14 +554,9 @@ public @interface MyTestConfig {
     @Rule
     public final SpringMethodRule springMethodRule = new SpringMethodRule();
 ----
-* The `ContextCache` that is used for caching ++ApplicationContext++s
-  between tests is now a public API with a default implementation that
-  can be replaced for custom caching needs.
-* `DefaultTestContext`, `DefaultBootstrapContext`, and
-  `DefaultCacheAwareContextLoaderDelegate` are now public classes in the
-  `support` subpackage, allowing for custom extensions.
-* ++TestContextBootstrapper++s are now responsible for building the
-  `TestContext`.
+* `AopTestUtils` is a new testing utility that allows developers to
+  obtain a reference to the underlying target object hidden behind one
+  or more Spring proxies.
 * `ReflectionTestUtils` now supports setting and getting `static` fields,
   including constants.
 * The original ordering of bean definition profiles declared via 
@@ -575,6 +570,18 @@ public @interface MyTestConfig {
   configuration for the `ApplicationContext`.
 * `@Sql` now supports execution of _inlined SQL statements_ via a new
   `statements` attribute.
+* The `ContextCache` that is used for caching ++ApplicationContext++s
+  between tests is now a public API with a default implementation that
+  can be replaced for custom caching needs.
+* `DefaultTestContext`, `DefaultBootstrapContext`, and
+  `DefaultCacheAwareContextLoaderDelegate` are now public classes in the
+  `support` subpackage, allowing for custom extensions.
+* ++TestContextBootstrapper++s are now responsible for building the
+  `TestContext`.
+* In the Spring MVC Test framework, `MvcResult` details can now be logged
+  at `DEBUG` level or written to a custom `OutputStream` or `Writer`. See
+  the new `log()`, `print(OutputStream)`, and `print(Writer)` methods in
+  `MockMvcResultHandlers` for details.
 * The JDBC XML namespace supports a new `database-name` attribute in
   `<jdbc:embedded-database>`, allowing developers to set unique names
   for embedded databases –- for example, via a SpEL expression or a
@@ -587,6 +594,3 @@ public @interface MyTestConfig {
 ** `EmbeddedDatabaseFactory.setGenerateUniqueDatabaseName()`
 ** `EmbeddedDatabaseBuilder.generateUniqueName()`
 ** `<jdbc:embedded-database generate-name="true" ... >`
-* `AopTestUtils` is a new testing utility that allows developers to
-  obtain a reference to the underlying target object hidden behind one
-  or more Spring proxies.
