Merge pull request #20 from prdoyle/ReadContextFilter-read-only

Read context filter only for safe HTTP methods

bosk-spring-boot-3/src/main/java/works/bosk/spring/boot/ReadContextFilter.java

@@ -1,24 +1,54 @@
 package works.bosk.spring.boot;
 
-import jakarta.servlet.Filter;
 import jakarta.servlet.FilterChain;
 import jakarta.servlet.ServletException;
-import jakarta.servlet.ServletRequest;
-import jakarta.servlet.ServletResponse;
+import jakarta.servlet.http.HttpServletRequest;
+import jakarta.servlet.http.HttpServletResponse;
 import java.io.IOException;
 import lombok.RequiredArgsConstructor;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import org.springframework.stereotype.Component;
+import org.springframework.web.bind.annotation.ControllerAdvice;
+import org.springframework.web.bind.annotation.ExceptionHandler;
+import org.springframework.web.filter.OncePerRequestFilter;
 import works.bosk.Bosk;
+import works.bosk.exceptions.NoReadContextException;
 
 @Component
+@ControllerAdvice
 @RequiredArgsConstructor
-public class ReadContextFilter implements Filter {
+public class ReadContextFilter extends OncePerRequestFilter {
 	private final Bosk<?> bosk;
 
 	@Override
-	public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
-		try (var __ = bosk.readContext()) {
-			chain.doFilter(request, response);
+	protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
+		if (automaticallyOpenReadContext(request)) {
+			try (var __ = bosk.readContext()) {
+				filterChain.doFilter(request, response);
+			}
+		} else {
+			filterChain.doFilter(request, response);
 		}
 	}
+
+	/**
+	 * The "safe" HTTP methods won't change server state, so there's no reason not to
+	 * open a
+	 */
+	private boolean automaticallyOpenReadContext(HttpServletRequest request) {
+		return switch (request.getMethod()) {
+			case "GET", "HEAD", "OPTIONS" -> true;
+			default -> false;
+		};
+	}
+
+	@ExceptionHandler(NoReadContextException.class)
+	void handleException(HttpServletRequest request, HttpServletResponse response) throws IOException {
+		LOGGER.error("Bosk read context was not opened automatically; the request handler method should open one by calling Bosk.readContext(). " +
+			"Request: {} {}", request.getMethod(), request.getRequestURI());
+		response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR);
+	}
+
+	private static final Logger LOGGER = LoggerFactory.getLogger(ReadContextFilter.class);
 }

example-hello/build.gradle

@@ -25,6 +25,7 @@ dependencies {
 	implementation 'org.springframework.boot:spring-boot-starter-web'
 	implementation 'org.springframework.boot:spring-boot-starter-actuator'
 	testImplementation 'org.springframework.boot:spring-boot-starter-test'
+	implementation project(':bosk-logback')
 
 	// A real project would pull this like any other library
 	implementation project(':bosk-spring-boot-3')

example-hello/src/main/java/works/bosk/hello/APIEndpoints.java

@@ -1,6 +1,7 @@
 package works.bosk.hello;
 
 import org.springframework.web.bind.annotation.GetMapping;
+import org.springframework.web.bind.annotation.PostMapping;
 import org.springframework.web.bind.annotation.RequestMapping;
 import org.springframework.web.bind.annotation.RestController;
 
@@ -21,4 +22,12 @@ GreetingDTO getHello() {
 	Object getTargets() {
 		return bosk.refs.targets().value();
 	}
+
+	/**
+	 * This should throw a 500. Useful for testing.
+	 */
+	@PostMapping("/noReadContext")
+	void noReadContext() {
+		bosk.rootReference().value();
+	}
 }

example-hello/src/main/java/works/bosk/hello/HelloApplication.java

@@ -2,6 +2,8 @@
 
 import org.springframework.boot.SpringApplication;
 import org.springframework.boot.autoconfigure.SpringBootApplication;
+import org.springframework.context.annotation.Bean;
+import works.bosk.logback.BoskLogFilter;
 
 @SpringBootApplication
 public class HelloApplication {
@@ -10,4 +12,9 @@ public static void main(String[] args) {
 		SpringApplication.run(HelloApplication.class, args);
 	}
 
+
+	@Bean
+	BoskLogFilter.LogController logController() {
+		return new BoskLogFilter.LogController();
+	}
 }

example-hello/src/main/java/works/bosk/hello/HelloBosk.java

@@ -9,11 +9,13 @@
 import works.bosk.exceptions.InvalidTypeException;
 import works.bosk.hello.state.BoskState;
 import works.bosk.hello.state.Target;
+import works.bosk.logback.BoskLogFilter;
+import works.bosk.logback.BoskLogFilter.LogController;
 
 @Component
 public class HelloBosk extends Bosk<BoskState> {
-	public HelloBosk() throws InvalidTypeException {
-		super("Hello", BoskState.class, HelloBosk::defaultRoot, Bosk::simpleDriver);
+	public HelloBosk(LogController logController) throws InvalidTypeException {
+		super("Hello", BoskState.class, HelloBosk::defaultRoot, BoskLogFilter.withController(logController));
 	}
 
 	public final Refs refs = buildReferences(Refs.class);

example-hello/src/main/resources/application.properties

@@ -1,2 +1,5 @@
 server.port=1111
 bosk.web.service-path=/bosk
+
+# Now that we use this in unit tests, quiet down the logging
+spring.main.banner-mode=off

example-hello/src/main/resources/logback.xml

@@ -0,0 +1,17 @@
+<configuration>
+	<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
+		<filter class="works.bosk.logback.BoskLogFilter"/>
+		<encoder>
+			<pattern>%d %-5level [%thread] [%X{bosk.name}]%X{bosk.MongoDriver.transaction}%X{bosk.MongoDriver.event} %logger{25}: %msg%n</pattern>
+		</encoder>
+		<immediateFlush>true</immediateFlush>
+	</appender>
+	<root level="WARN">
+		<appender-ref ref="CONSOLE" />
+	</root>
+
+	<!-- How to add more tracing during unit tests
+	<logger name="works.bosk" level="INFO"/>
+	 -->
+
+</configuration>

example-hello/src/test/java/works/bosk/hello/HelloServiceEndpointsTest.java

@@ -4,26 +4,35 @@
 import java.io.IOException;
 import java.util.List;
 import java.util.stream.Stream;
+import org.junit.jupiter.api.AfterEach;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.params.ParameterizedTest;
 import org.junit.jupiter.params.provider.ValueSource;
+import org.slf4j.MDC;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.boot.test.autoconfigure.web.servlet.AutoConfigureMockMvc;
 import org.springframework.boot.test.context.SpringBootTest;
 import org.springframework.test.web.servlet.MockMvc;
+import org.springframework.web.servlet.mvc.support.DefaultHandlerExceptionResolver;
 import works.bosk.Catalog;
 import works.bosk.Identifier;
 import works.bosk.hello.state.BoskState;
 import works.bosk.hello.state.Target;
+import works.bosk.logback.BoskLogFilter;
+import works.bosk.spring.boot.ReadContextFilter;
 
+import static ch.qos.logback.classic.Level.ERROR;
+import static ch.qos.logback.classic.Level.OFF;
 import static org.springframework.http.MediaType.APPLICATION_FORM_URLENCODED;
 import static org.springframework.http.MediaType.APPLICATION_JSON;
 import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.delete;
 import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.get;
+import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.post;
 import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.put;
 import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.content;
 import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status;
+import static works.bosk.logging.MdcKeys.BOSK_INSTANCE_ID;
 
 @SpringBootTest(classes = HelloApplication.class)
 @AutoConfigureMockMvc
@@ -40,10 +49,23 @@ public class HelloServiceEndpointsTest {
 	@Autowired
 	HelloBosk bosk;
 
+	@Autowired
+	BoskLogFilter.LogController logController;
+
 	@BeforeEach
 	void setupBosk() throws IOException, InterruptedException {
 		bosk.driver().submitReplacement(bosk.rootReference(), INITIAL_STATE);
 		bosk.driver().flush();
+
+		// So LogController works even outside driver operations.
+		// We do this after resetting the bosk because any oddities before that point
+		// are more likely to be caused by a prior test.
+		MDC.put(BOSK_INSTANCE_ID, bosk.instanceID().toString());
+	}
+
+	@AfterEach
+	void cleanup() {
+		MDC.remove(BOSK_INSTANCE_ID);
 	}
 
 	@ParameterizedTest
@@ -105,6 +127,7 @@ void get_existingTarget_works() throws Exception {
 
 	@Test
 	void get_nonexistentTarget_reportsError() throws Exception {
+		logController.setLogging(OFF, ReadContextFilter.class);
 		mvc.perform(get("/bosk/targets/nonexistent"))
 			.andExpect(status().isNotFound());
 	}
@@ -138,6 +161,7 @@ void put_newTarget_works() throws Exception {
 
 	@Test
 	void put_wrongContentType_reportsError() throws Exception {
+		logController.setLogging(ERROR, DefaultHandlerExceptionResolver.class);
 		mvc.perform(put("/bosk/targets/" + INITIAL_TARGET.id())
 				.contentType(APPLICATION_FORM_URLENCODED)
 				.content(mapper.writeValueAsString(INITIAL_TARGET)))
@@ -153,6 +177,13 @@ void delete_existingTarget_works() throws Exception {
 		assertHello();
 	}
 
+	@Test
+	void postWithoutReadContext_reportsError() throws Exception {
+		logController.setLogging(OFF, ReadContextFilter.class);
+		mvc.perform(post("/api/noReadContext"))
+			.andExpect(status().isInternalServerError());
+	}
+
 	private void assertGetReturns(Object object, String uri) throws Exception {
 		String expected = mapper.writeValueAsString(object);
 		mvc.perform(get(uri))