Add filter-interceptor-aop module: servlet Filter vs HandlerInterceptor vs @Aspect on Spring Boot 4.1.2, the real order on Tomcat and MockMvc, error/404/async/body/Security traps

Co-Authored-By: Claude Sonnet 5.5 <[email protected]>
Claude-Session: https://claude.ai/code/session_017ic4b6Kg9RWSTJzyz6KP9X
This commit is contained in:
2026-10-31 04:05:43 +00:00
committed by Claude
co-authored by Claude Sonnet 5.5
parent 3a30194459
commit 51913ad9d4
79 changed files with 3661 additions and 0 deletions
+1
View File
@@ -10,6 +10,7 @@ files.
| Directory | Article | What it demonstrates | | Directory | Article | What it demonstrates |
|---|---|---| |---|---|---|
| [`pdf-invoice/`](pdf-invoice) | [Generate PDF Invoices in Spring Boot: OpenPDF vs iText vs Flying Saucer (HTML to PDF)](https://ankurm.com/spring-boot-generate-pdf-invoice-openpdf-itext-flying-saucer/) | one invoice rendered by OpenPDF 3.0.5, iText Core 9.8.0 (AGPL 3 or commercial) and Flying Saucer 10.7.0 from a Thymeleaf template, with embedded Noto Sans Devanagari: none of the three shapes Marathi/Hindi conjuncts by default (checked by rendering to PNG against a libraqm reference), OpenPDF's `GlyphLayoutManager` does but breaks text extraction until `ActualText` is on, OpenPDF's static `LayoutProcessor` is JVM-global and breaks other writers, Apache FOP on the classpath did not help, streamed vs buffered failure (`200` + curl exit 18 vs `500`), font subsetting, indicative per-invoice timings | | [`pdf-invoice/`](pdf-invoice) | [Generate PDF Invoices in Spring Boot: OpenPDF vs iText vs Flying Saucer (HTML to PDF)](https://ankurm.com/spring-boot-generate-pdf-invoice-openpdf-itext-flying-saucer/) | one invoice rendered by OpenPDF 3.0.5, iText Core 9.8.0 (AGPL 3 or commercial) and Flying Saucer 10.7.0 from a Thymeleaf template, with embedded Noto Sans Devanagari: none of the three shapes Marathi/Hindi conjuncts by default (checked by rendering to PNG against a libraqm reference), OpenPDF's `GlyphLayoutManager` does but breaks text extraction until `ActualText` is on, OpenPDF's static `LayoutProcessor` is JVM-global and breaks other writers, Apache FOP on the classpath did not help, streamed vs buffered failure (`200` + curl exit 18 vs `500`), font subsetting, indicative per-invoice timings |
| [`filter-interceptor-aop/`](filter-interceptor-aop) | [Filter vs HandlerInterceptor vs AOP in Spring Boot 4: Which Runs When](https://ankurm.com/spring-boot-filter-vs-handlerinterceptor-vs-aop-which-runs-when/) | the real order of a servlet filter, a `HandlerInterceptor` and an `@Aspect` printed from a running Tomcat and from MockMvc, the callbacks that still fire (and the ones that do not) after an exception, a 404, a `preHandle` that returns false and an async request, `afterCompletion` seeing `ex=null` after `@ControllerAdvice`, a header added in `postHandle` silently lost, a request body read twice, `ContentCachingResponseWrapper` returning an empty 200, Spring Security 7's chain sitting at order -100, a filter bean running twice, the Framework 7 path-matching removals read with `javap`, and the three self-invocation-style cases an aspect never sees |
| [`excel-export/`](excel-export) | [Export Excel and CSV from Spring Boot: Streaming 1 Million Rows with Apache POI SXSSF](https://ankurm.com/spring-boot-export-excel-csv-streaming-poi-sxssf/) | XSSF vs SXSSF under a fixed 512 MB heap (XSSF out of memory between 50,000 and 100,000 rows and at 1,000,000 rows even with 3 GB), 1,000,000 rows streamed with `StreamingResponseBody` under a 64 MB heap, sheet rolling at 1,048,576 rows, `compressTempFiles` cutting the spill from 475 MB to 56 MB, OpenCSV swallowing write errors, and an SXSSF file LibreOffice will not open | | [`excel-export/`](excel-export) | [Export Excel and CSV from Spring Boot: Streaming 1 Million Rows with Apache POI SXSSF](https://ankurm.com/spring-boot-export-excel-csv-streaming-poi-sxssf/) | XSSF vs SXSSF under a fixed 512 MB heap (XSSF out of memory between 50,000 and 100,000 rows and at 1,000,000 rows even with 3 GB), 1,000,000 rows streamed with `StreamingResponseBody` under a 64 MB heap, sheet rolling at 1,048,576 rows, `compressTempFiles` cutting the spill from 475 MB to 56 MB, OpenCSV swallowing write errors, and an SXSSF file LibreOffice will not open |
| [`thymeleaf-htmx/`](thymeleaf-htmx) | [Spring Boot 4 + Thymeleaf + htmx: Server-Side CRUD UI in 2026](https://ankurm.com/spring-boot-thymeleaf-htmx-crud-ui/) | one URL answering as full page or fragment on `HX-Request`, a Thymeleaf layout, 422 validation re-render, pagination, inline edit and delete, 10 MockMvc tests plus a headless-Chromium check that observed htmx 2 ignoring a 204 and (without a config tag) a 422 | | [`thymeleaf-htmx/`](thymeleaf-htmx) | [Spring Boot 4 + Thymeleaf + htmx: Server-Side CRUD UI in 2026](https://ankurm.com/spring-boot-thymeleaf-htmx-crud-ui/) | one URL answering as full page or fragment on `HX-Request`, a Thymeleaf layout, 422 validation re-render, pagination, inline edit and delete, 10 MockMvc tests plus a headless-Chromium check that observed htmx 2 ignoring a 204 and (without a config tag) a 422 |
| [`rate-limit/`](rate-limit) | [Rate Limiting Spring Boot APIs with Bucket4j and Redis: Per-User, Per-Key and Global Limits](https://ankurm.com/spring-boot-rate-limiting-bucket4j-redis/) | per-user, per-API-key and global token buckets in a servlet filter on Bucket4j 8.21 (`bucket4j_jdk17-*`), `429` with `Retry-After` and `X-RateLimit-*` headers, two application instances sharing one Redis bucket and 200 concurrent requests letting exactly 20 through, a limit raised in `application.yml` that does not change buckets already stored in Redis until a config version is bumped, a client clock 30 s ahead handing out tokens another instance already spent, and fail-open versus fail-closed when Redis dies | | [`rate-limit/`](rate-limit) | [Rate Limiting Spring Boot APIs with Bucket4j and Redis: Per-User, Per-Key and Global Limits](https://ankurm.com/spring-boot-rate-limiting-bucket4j-redis/) | per-user, per-API-key and global token buckets in a servlet filter on Bucket4j 8.21 (`bucket4j_jdk17-*`), `429` with `Retry-After` and `X-RateLimit-*` headers, two application instances sharing one Redis bucket and 200 concurrent requests letting exactly 20 through, a limit raised in `application.yml` that does not change buckets already stored in Redis until a config version is bumped, a client clock 30 s ahead handing out tokens another instance already spent, and fail-open versus fail-closed when Redis dies |
+91
View File
@@ -0,0 +1,91 @@
# filter-interceptor-aop
Companion module for [**Filter vs HandlerInterceptor vs AOP in Spring Boot 4: Which Runs When**](https://ankurm.com/spring-boot-filter-vs-handlerinterceptor-vs-aop-which-runs-when/)
on ankurm.com. A servlet `Filter`, a Spring MVC `HandlerInterceptor` and an `@Aspect` all wrap a request; this module
prints the order they really run in, on a real Tomcat and under MockMvc, and then breaks the assumptions around it
(errors, 404, static files, async, a body read twice, Spring Security).
`mvn test` regenerates every transcript in [`output/`](output) (19 tests). Each test writes its transcript and asserts the same
facts, so a number quoted in the article is an assertion that fails the build when it stops being true.
## Versions
| | |
|---|---|
| Spring Boot | 4.1.2 |
| Spring Framework | 7.0.10 |
| Spring Security | 7.1.2 |
| Tomcat (embedded) | 11.0.27 |
| AspectJ weaver | 1.9.25.1 |
| JDK | Eclipse Temurin 25.0.5 (LTS) |
The AOP starter is **`spring-boot-starter-aspectj`**. `spring-boot-starter-aop` has no 4.x release (its last version is 3.5.16).
## Quickstart
```bash
export JAVA_HOME=/path/to/jdk-25
mvn test # 19 tests, rewrites output/01..19
./scripts/run.sh # app on :8080
curl localhost:8080/diag/filters # Tomcat's real filter chain, in order
./scripts/run.sh security # same app behind Spring Security 7 (HTTP Basic demo:demo)
./scripts/run-all.sh # tests + the scripts behind output/20, 21 (Maven Central) and 22 (jars in ~/.m2)
```
## What is where
| Package | Contents |
|---|---|
| `trace` | `Trace`: every component writes one line here, in the order it really runs (delete before shipping) |
| `filter` | `RawFilter` (plain `Filter`, `@Order(5)`), `AccessLogFilter` (`OncePerRequestFilter` through a `FilterRegistrationBean`, order 10), `ApiKeyFilter` (auth, 20), `VisibilityFilter` (25), `BodyFilter` (request/response wrappers, 30), `FaultFilter` (throws, 40) |
| `interceptor` | `TraceInterceptor` (A and B), `GateInterceptor` (returns false), `RoleInterceptor` (reads `@RequiresRole`), `TimingInterceptor`, `LateHeaderInterceptor`, `VisibilityInterceptor`, `WebConfig` |
| `aop` | `ControllerAspect`, `ServiceAspect`, `VisibilityAspect` |
| `service` | `GreetingService` (self-invocation, private method, `new Helper()`), `FixedGreetingService` (the `@Lazy` self-reference fix) |
| `web` | `HelloController`, `ApiExceptionHandler`, `DiagController` (`/diag/filters`), `TracingDispatcherServlet` |
| `security` | `SecurityDemoConfig`, only with the `security` profile |
## Endpoints
| Endpoint | Shows |
|---|---|
| `GET /api/hello/{name}` | the full happy-path order |
| `GET /api/boom`, `/api/service-boom`, `/api/unhandled` | handled, handled-from-service and unhandled exceptions |
| `POST /api/echo` + `X-Body-Mode: consume\|cache\|consume-wrapped\|replay` | the request body read twice |
| `GET /api/hello/{name}` + `X-Resp-Mode: copy\|forget` | `ContentCachingResponseWrapper` and `copyBodyToResponse()` |
| `GET /api/secure/data` + `X-Api-Key: demo-key` | a filter rejecting a request |
| `GET /api/admin/report` + `X-Role: admin` | an interceptor reading an annotation |
| `GET /api/gated/hello?mode=write\|silent` | `preHandle` returning false |
| `GET /api/async-callable`, `/api/async-deferred` | async dispatch |
| `GET /api/late/body` | a header added in `postHandle` |
| `GET /api/visibility/{id}` | what each layer can see |
| `GET /api/twice/{name}`, `/api/private/{name}`, `/api/helper/{name}`, `/api/twice-fixed/{name}` | what an aspect does not see |
## Index of captured output
| File | Contents |
|---|---|
| [`01-versions-and-jars.txt`](output/01-versions-and-jars.txt) | versions, the AOP starter's pom, jars, Framework 7 API facts read by reflection |
| [`02-filter-chain-order.txt`](output/02-filter-chain-order.txt) | Tomcat's real filter chain and dispatcher types |
| [`03-happy-path.txt`](output/03-happy-path.txt) | one request, every layer, in order |
| [`04-exceptions.txt`](output/04-exceptions.txt) | handled, service, unhandled and filter exceptions |
| [`05-static-404-error-dispatch.txt`](output/05-static-404-error-dispatch.txt) | static resource, 404, 405 and the ERROR dispatch |
| [`06-short-circuits.txt`](output/06-short-circuits.txt) | filter 401, interceptor 403, `preHandle` false |
| [`07-async.txt`](output/07-async.txt) | `Callable` and `DeferredResult`, with threads |
| [`08-request-body.txt`](output/08-request-body.txt) | the body read twice, five ways, and the response wrapper |
| [`09-visibility.txt`](output/09-visibility.txt) | what a filter, an interceptor and an aspect can see |
| [`10-timing.txt`](output/10-timing.txt) | elapsed time per layer (indicative) |
| [`11-late-header.txt`](output/11-late-header.txt) | a header set after the response is committed |
| [`12-no-handler.txt`](output/12-no-handler.txt) | `spring.web.resources.add-mappings=false` |
| [`13-handler-cast.txt`](output/13-handler-cast.txt) | the unchecked `HandlerMethod` cast |
| [`14-path-patterns.txt`](output/14-path-patterns.txt) | which `addPathPatterns` patterns match which URLs |
| [`15-aop-traps.txt`](output/15-aop-traps.txt) | self-invocation, private method, `new`, and the fix |
| [`16-security-order.txt`](output/16-security-order.txt) | Spring Security's chain among the servlet filters |
| [`17-security-double-registration.txt`](output/17-security-double-registration.txt) | a filter bean that runs twice |
| [`18-security-double-registration-fixed.txt`](output/18-security-double-registration-fixed.txt) | the same, fixed |
| [`19-mockmvc-vs-server.txt`](output/19-mockmvc-vs-server.txt) | the same requests through MockMvc and Tomcat |
| [`20-central-versions.txt`](output/20-central-versions.txt) | Maven Central metadata (script) |
| [`21-framework-6.2-vs-7.0.txt`](output/21-framework-6.2-vs-7.0.txt) | `javap` of the interceptor and path-matching API in 6.2.19 vs 7.0.10 (script) |
| [`22-boot-bytecode-facts.txt`](output/22-boot-bytecode-facts.txt) | bytecode facts: default filter dispatcher types, the `dispatcherServlet` back-off, the Security filter order constant, `TestDispatcherServlet` (script) |
Timing in `10-timing.txt` varies between runs; everything else is identical on a rerun.
Thread names in `07-async.txt` are relabelled (`tomcat-1`, `mvc-task-1`) so the file is reproducible.
@@ -0,0 +1,47 @@
### Versions on the classpath
JDK 25.0.5+8-LTS
Spring Boot 4.1.2
Spring Framework 7.0.10
Spring Security 7.1.2
Tomcat 11.0.27.0
AspectJ weaver aspectjweaver-1.9.25.1.jar
### The Boot 4 AOP starter, read from its published pom in ~/.m2
spring-boot-starter-aspectj 4.1.2 depends on [aspectjweaver, spring-aop, spring-boot-starter]
spring-boot-starter-aop: no 4.x release exists on Maven Central (see 20-central-versions.txt)
### Which jar each piece lives in
org.springframework.boot.autoconfigure.aop.AopAutoConfiguration spring-boot-autoconfigure-4.1.2.jar
org.springframework.boot.web.servlet.FilterRegistrationBean spring-boot-4.1.2.jar
org.springframework.boot.servlet.filter.OrderedFilter spring-boot-servlet-4.1.2.jar
org.springframework.boot.tomcat.TomcatWebServer spring-boot-tomcat-4.1.2.jar
org.springframework.boot.webmvc.autoconfigure.DispatcherServletAutoConfiguration spring-boot-webmvc-4.1.2.jar
org.springframework.web.servlet.handler.MappedInterceptor spring-webmvc-7.0.10.jar
org.springframework.web.filter.OncePerRequestFilter spring-web-7.0.10.jar
org.springframework.web.servlet.AsyncHandlerInterceptor spring-webmvc-7.0.10.jar
org.springframework.boot.security.autoconfigure.web.servlet.SecurityFilterAutoConfiguration spring-boot-security-4.1.2.jar
### Orders of the filters Boot registers (constants read from the jars)
OrderedCharacterEncodingFilter.getOrder() = -2147483648
OrderedFormContentFilter.DEFAULT_ORDER = -9900
OrderedRequestContextFilter.getOrder() = -105
SecurityFilterProperties.DEFAULT_FILTER_ORDER = -100
Ordered.LOWEST_PRECEDENCE (no @Order) = 2147483647
### OncePerRequestFilter defaults (a subclass asked at runtime)
shouldNotFilterErrorDispatch() = true
shouldNotFilterAsyncDispatch() = true
### InterceptorRegistration public methods (Framework 7.0.10)
[addPathPatterns, excludeHttpMethods, excludePathPatterns, includeHttpMethods, order, pathMatcher [deprecated]]
### PathMatchConfigurer public setters and their @Deprecated flag
setPathMatcher @Deprecated(since="7.0", forRemoval=true)
setPatternParser -
setUrlPathHelper @Deprecated(since="7.0", forRemoval=true)
### PathPatternParser: public setters, and whether the trailing-slash switches still exist
setters = [setCaseSensitive, setPathOptions]
caseSensitive = true
has setMatchOptionalTrailingSeparator = false
has PathMatchConfigurer.setUseTrailingSlashMatch = false
@@ -0,0 +1,25 @@
### Tomcat's real filter chain (StandardContext.findFilterMaps), outermost first
## filter name url patterns dispatcher types
1 characterEncodingFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
2 formContentFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
3 requestContextFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
4 rawFilter [/*] [REQUEST]
5 accessLog [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
6 apiKeyFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
7 visibilityFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
8 bodyFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
9 faultFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
10 Tomcat WebSocket (JSR356) Filter [/*] [FORWARD, REQUEST]
### The same list from GET /diag/filters over HTTP
$ curl localhost:PORT/diag/filters
1 characterEncodingFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
2 formContentFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
3 requestContextFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
4 rawFilter [/*] [REQUEST]
5 accessLog [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
6 apiKeyFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
7 visibilityFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
8 bodyFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
9 faultFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
10 Tomcat WebSocket (JSR356) Filter [/*] [FORWARD, REQUEST]
@@ -0,0 +1,19 @@
### GET /api/hello/ankur on a real Tomcat
HTTP 200 body=Hello, ankur
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
06 REQUEST aspect:controller before HelloController#hello args=[ankur]
07 REQUEST controller hello(ankur)
08 REQUEST aspect:service before GreetingService#greet args=[ankur]
09 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
10 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
11 REQUEST interceptor:B postHandle status=200 modelAndView=null
12 REQUEST interceptor:A postHandle status=200 modelAndView=null
13 REQUEST interceptor:B afterCompletion ex=null
14 REQUEST interceptor:A afterCompletion ex=null
15 REQUEST servlet:DispatcherServlet doDispatch end
16 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
17 REQUEST filter:raw(order 5) after chain
@@ -0,0 +1,76 @@
### GET /api/boom: controller throws, @RestControllerAdvice handles it
HTTP 500 body={"handled":"controller boom"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/boom
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#boom
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#boom
06 REQUEST aspect:controller before HelloController#boom args=[]
07 REQUEST controller boom() about to throw
08 REQUEST aspect:controller after HelloController#boom THREW IllegalStateException
09 REQUEST advice:@ExceptionHandler handling IllegalStateException: controller boom
10 REQUEST interceptor:B afterCompletion ex=null
11 REQUEST interceptor:A afterCompletion ex=null
12 REQUEST servlet:DispatcherServlet doDispatch end
13 REQUEST filter:accessLog(order 10) after chain status=500 asyncStarted=false
14 REQUEST filter:raw(order 5) after chain
### GET /api/service-boom: the service throws, the controller never catches
HTTP 500 body={"handled":"service boom"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/service-boom
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#serviceBoom
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#serviceBoom
06 REQUEST aspect:controller before HelloController#serviceBoom args=[]
07 REQUEST aspect:service before GreetingService#fail args=[]
08 REQUEST aspect:service after GreetingService#fail THREW IllegalStateException
09 REQUEST aspect:controller after HelloController#serviceBoom THREW IllegalStateException
10 REQUEST advice:@ExceptionHandler handling IllegalStateException: service boom
11 REQUEST interceptor:B afterCompletion ex=null
12 REQUEST interceptor:A afterCompletion ex=null
13 REQUEST servlet:DispatcherServlet doDispatch end
14 REQUEST filter:accessLog(order 10) after chain status=500 asyncStarted=false
15 REQUEST filter:raw(order 5) after chain
### GET /api/unhandled: nobody handles it, Boot's /error takes over
HTTP 500 body={"timestamp":"...","status":500,"error":"Internal Server Error","path":"/api/unhandled"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/unhandled
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#unhandled
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#unhandled
06 REQUEST aspect:controller before HelloController#unhandled args=[]
07 REQUEST controller unhandled() about to throw
08 REQUEST aspect:controller after HelloController#unhandled THREW UnsupportedOperationException
09 REQUEST interceptor:B afterCompletion ex=UnsupportedOperationException
10 REQUEST interceptor:A afterCompletion ex=UnsupportedOperationException
11 REQUEST servlet:DispatcherServlet doDispatch end
12 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
13 REQUEST filter:raw(order 5) after chain
14 ERROR servlet:DispatcherServlet doDispatch start
15 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
16 ERROR interceptor:A error attributes: status=500 exception=ServletException
17 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
18 ERROR interceptor:B postHandle status=500 modelAndView=null
19 ERROR interceptor:A postHandle status=500 modelAndView=null
20 ERROR interceptor:B afterCompletion ex=null
21 ERROR interceptor:A afterCompletion ex=null
22 ERROR servlet:DispatcherServlet doDispatch end
### GET /api/hello/x with X-Filter-Throw: the FILTER throws
HTTP 500 body={"timestamp":"...","status":500,"error":"Internal Server Error","path":"/api/hello/x"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/hello/x
03 REQUEST filter:fault(order 40) throwing IllegalStateException
04 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
05 REQUEST filter:raw(order 5) after chain
06 ERROR servlet:DispatcherServlet doDispatch start
07 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
08 ERROR interceptor:A error attributes: status=500 exception=IllegalStateException
09 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
10 ERROR interceptor:B postHandle status=500 modelAndView=null
11 ERROR interceptor:A postHandle status=500 modelAndView=null
12 ERROR interceptor:B afterCompletion ex=null
13 ERROR interceptor:A afterCompletion ex=null
14 ERROR servlet:DispatcherServlet doDispatch end
@@ -0,0 +1,54 @@
### GET /hello.txt: a static resource
HTTP 200 body=static file served by ResourceHttpRequestHandler
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /hello.txt
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=ResourceHttpRequestHandler
05 REQUEST interceptor:B preHandle handler=ResourceHttpRequestHandler
06 REQUEST interceptor:B postHandle status=200 modelAndView=null
07 REQUEST interceptor:A postHandle status=200 modelAndView=null
08 REQUEST interceptor:B afterCompletion ex=null
09 REQUEST interceptor:A afterCompletion ex=null
10 REQUEST servlet:DispatcherServlet doDispatch end
11 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
12 REQUEST filter:raw(order 5) after chain
### GET /nope: no controller, no file
HTTP 404 body={"timestamp":"...","status":404,"error":"Not Found","path":"/nope"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /nope
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=ResourceHttpRequestHandler
05 REQUEST interceptor:B preHandle handler=ResourceHttpRequestHandler
06 REQUEST interceptor:B afterCompletion ex=null
07 REQUEST interceptor:A afterCompletion ex=null
08 REQUEST servlet:DispatcherServlet doDispatch end
09 REQUEST filter:accessLog(order 10) after chain status=404 asyncStarted=false
10 REQUEST filter:raw(order 5) after chain
11 ERROR servlet:DispatcherServlet doDispatch start
12 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
13 ERROR interceptor:A error attributes: status=404 exception=null
14 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
15 ERROR interceptor:B postHandle status=404 modelAndView=null
16 ERROR interceptor:A postHandle status=404 modelAndView=null
17 ERROR interceptor:B afterCompletion ex=null
18 ERROR interceptor:A afterCompletion ex=null
19 ERROR servlet:DispatcherServlet doDispatch end
### POST /api/ping: the path exists, the method does not
HTTP 405 body={"timestamp":"...","status":405,"error":"Method Not Allowed","path":"/api/ping"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain POST /api/ping
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST servlet:DispatcherServlet doDispatch end
05 REQUEST filter:accessLog(order 10) after chain status=405 asyncStarted=false
06 REQUEST filter:raw(order 5) after chain
07 ERROR servlet:DispatcherServlet doDispatch start
08 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
09 ERROR interceptor:A error attributes: status=405 exception=null
10 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
11 ERROR interceptor:B postHandle status=405 modelAndView=null
12 ERROR interceptor:A postHandle status=405 modelAndView=null
13 ERROR interceptor:B afterCompletion ex=null
14 ERROR interceptor:A afterCompletion ex=null
15 ERROR servlet:DispatcherServlet doDispatch end
@@ -0,0 +1,111 @@
### GET /api/secure/data without a key: the FILTER answers
HTTP 401 body={"error":"missing or wrong X-Api-Key"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/secure/data
03 REQUEST filter:apiKey(order 20) REJECT 401, chain stops here
04 REQUEST filter:accessLog(order 10) after chain status=401 asyncStarted=false
05 REQUEST filter:raw(order 5) after chain
### GET /api/secure/data with the key
HTTP 200 body=secret data
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/secure/data
03 REQUEST filter:apiKey(order 20) key ok, continue
04 REQUEST servlet:DispatcherServlet doDispatch start
05 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#secure
06 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#secure
07 REQUEST aspect:controller before HelloController#secure args=[]
08 REQUEST controller secure()
09 REQUEST aspect:controller after HelloController#secure returned=secret data (String)
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST servlet:DispatcherServlet doDispatch end
15 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
16 REQUEST filter:raw(order 5) after chain
### GET /api/admin/report as a plain user: the INTERCEPTOR denies
HTTP 403 body={"timestamp":"...","status":403,"error":"Forbidden","path":"/api/admin/report"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/admin/report
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#admin
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#admin
06 REQUEST interceptor:role @RequiresRole("admin") on admin, X-Role=user -> deny 403
07 REQUEST interceptor:B afterCompletion ex=null
08 REQUEST interceptor:A afterCompletion ex=null
09 REQUEST servlet:DispatcherServlet doDispatch end
10 REQUEST filter:accessLog(order 10) after chain status=403 asyncStarted=false
11 REQUEST filter:raw(order 5) after chain
12 ERROR servlet:DispatcherServlet doDispatch start
13 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
14 ERROR interceptor:A error attributes: status=403 exception=null
15 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
16 ERROR interceptor:B postHandle status=403 modelAndView=null
17 ERROR interceptor:A postHandle status=403 modelAndView=null
18 ERROR interceptor:B afterCompletion ex=null
19 ERROR interceptor:A afterCompletion ex=null
20 ERROR servlet:DispatcherServlet doDispatch end
### GET /api/admin/report as admin
HTTP 200 body=admin report
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/admin/report
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#admin
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#admin
06 REQUEST interceptor:role @RequiresRole("admin") on admin, X-Role=admin -> allow
07 REQUEST aspect:controller before HelloController#admin args=[]
08 REQUEST controller admin()
09 REQUEST aspect:controller after HelloController#admin returned=admin report (String)
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST servlet:DispatcherServlet doDispatch end
15 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
16 REQUEST filter:raw(order 5) after chain
### GET /api/gated/hello: gate returns true
HTTP 200 body=gated hello
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/gated/hello
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#gated
05 REQUEST interceptor:gate preHandle -> true
06 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#gated
07 REQUEST aspect:controller before HelloController#gated args=[]
08 REQUEST controller gated()
09 REQUEST aspect:controller after HelloController#gated returned=gated hello (String)
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST servlet:DispatcherServlet doDispatch end
15 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
16 REQUEST filter:raw(order 5) after chain
### GET /api/gated/hello?mode=write: gate returns false after writing a 403 body
HTTP 403 body={"error":"gate closed"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/gated/hello
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#gated
05 REQUEST interceptor:gate preHandle -> FALSE (mode=write)
06 REQUEST interceptor:A afterCompletion ex=null
07 REQUEST servlet:DispatcherServlet doDispatch end
08 REQUEST filter:accessLog(order 10) after chain status=403 asyncStarted=false
09 REQUEST filter:raw(order 5) after chain
### GET /api/gated/hello?mode=silent: gate returns false and writes nothing
HTTP 200 (empty body)
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/gated/hello
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#gated
05 REQUEST interceptor:gate preHandle -> FALSE (mode=silent)
06 REQUEST interceptor:A afterCompletion ex=null
07 REQUEST servlet:DispatcherServlet doDispatch end
08 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
09 REQUEST filter:raw(order 5) after chain
@@ -0,0 +1,49 @@
### GET /api/async-callable: returns a Callable
HTTP 200 body=callable-done
01 REQUEST filter:raw(order 5) before chain <tomcat-1>
02 REQUEST filter:accessLog(order 10) before chain GET /api/async-callable <tomcat-1>
03 REQUEST servlet:DispatcherServlet doDispatch start <tomcat-1>
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#asyncCallable <tomcat-1>
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#asyncCallable <tomcat-1>
06 REQUEST aspect:controller before HelloController#asyncCallable args=[] <tomcat-1>
07 REQUEST controller asyncCallable() returns a Callable <tomcat-1>
08 REQUEST aspect:controller after HelloController#asyncCallable returned=a lambda (HelloController$$Lambda) <tomcat-1>
09 REQUEST interceptor:B afterConcurrentHandlingStarted (async began, no postHandle/afterCompletion yet) <tomcat-1>
10 REQUEST interceptor:A afterConcurrentHandlingStarted (async began, no postHandle/afterCompletion yet) <tomcat-1>
11 REQUEST servlet:DispatcherServlet doDispatch end <tomcat-1>
12 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=true <tomcat-1>
13 REQUEST filter:raw(order 5) after chain <tomcat-1>
14 REQUEST callable finished after 100 ms, returning <mvc-task-1>
15 ASYNC servlet:DispatcherServlet doDispatch start <tomcat-2>
16 ASYNC interceptor:A preHandle handler=HandlerMethod HelloController#asyncCallable <tomcat-2>
17 ASYNC interceptor:B preHandle handler=HandlerMethod HelloController#asyncCallable <tomcat-2>
18 ASYNC interceptor:B postHandle status=200 modelAndView=null <tomcat-2>
19 ASYNC interceptor:A postHandle status=200 modelAndView=null <tomcat-2>
20 ASYNC interceptor:B afterCompletion ex=null <tomcat-2>
21 ASYNC interceptor:A afterCompletion ex=null <tomcat-2>
22 ASYNC servlet:DispatcherServlet doDispatch end <tomcat-2>
### GET /api/async-deferred: returns a DeferredResult completed by another thread
HTTP 200 body=deferred-done
01 REQUEST filter:raw(order 5) before chain <tomcat-1>
02 REQUEST filter:accessLog(order 10) before chain GET /api/async-deferred <tomcat-1>
03 REQUEST servlet:DispatcherServlet doDispatch start <tomcat-1>
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#asyncDeferred <tomcat-1>
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#asyncDeferred <tomcat-1>
06 REQUEST aspect:controller before HelloController#asyncDeferred args=[] <tomcat-1>
07 REQUEST controller asyncDeferred() returns a DeferredResult <tomcat-1>
08 REQUEST aspect:controller after HelloController#asyncDeferred returned=an instance of DeferredResult (DeferredResult) <tomcat-1>
09 REQUEST interceptor:B afterConcurrentHandlingStarted (async began, no postHandle/afterCompletion yet) <tomcat-1>
10 REQUEST interceptor:A afterConcurrentHandlingStarted (async began, no postHandle/afterCompletion yet) <tomcat-1>
11 REQUEST servlet:DispatcherServlet doDispatch end <tomcat-1>
12 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=true <tomcat-1>
13 REQUEST filter:raw(order 5) after chain <tomcat-1>
14 - deferred setResult <demo-scheduler>
15 ASYNC servlet:DispatcherServlet doDispatch start <tomcat-2>
16 ASYNC interceptor:A preHandle handler=HandlerMethod HelloController#asyncDeferred <tomcat-2>
17 ASYNC interceptor:B preHandle handler=HandlerMethod HelloController#asyncDeferred <tomcat-2>
18 ASYNC interceptor:B postHandle status=200 modelAndView=null <tomcat-2>
19 ASYNC interceptor:A postHandle status=200 modelAndView=null <tomcat-2>
20 ASYNC interceptor:B afterCompletion ex=null <tomcat-2>
21 ASYNC interceptor:A afterCompletion ex=null <tomcat-2>
22 ASYNC servlet:DispatcherServlet doDispatch end <tomcat-2>
@@ -0,0 +1,131 @@
### POST /api/echo "hello body" X-Body-Mode=none
HTTP 200 body=echo:hello body
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain POST /api/echo
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#echo
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#echo
06 REQUEST aspect:controller before HelloController#echo args=[hello body]
07 REQUEST controller echo received 10 chars
08 REQUEST aspect:controller after HelloController#echo returned=echo:hello body (String)
09 REQUEST interceptor:B postHandle status=200 modelAndView=null
10 REQUEST interceptor:A postHandle status=200 modelAndView=null
11 REQUEST interceptor:B afterCompletion ex=null
12 REQUEST interceptor:A afterCompletion ex=null
13 REQUEST servlet:DispatcherServlet doDispatch end
14 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
15 REQUEST filter:raw(order 5) after chain
### POST /api/echo "hello body" X-Body-Mode=consume
HTTP 400 body={"handled":"unreadable body"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain POST /api/echo
03 REQUEST filter:body(order 30) read raw stream: 10 bytes, passing the ORIGINAL request on
04 REQUEST servlet:DispatcherServlet doDispatch start
05 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#echo
06 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#echo
07 REQUEST advice:@ExceptionHandler handling HttpMessageNotReadableException: Required request body is missing: public java.lang.String com.ankurm.filteraop.web.HelloController.echo(java.lang.String)
08 REQUEST interceptor:B afterCompletion ex=null
09 REQUEST interceptor:A afterCompletion ex=null
10 REQUEST servlet:DispatcherServlet doDispatch end
11 REQUEST filter:accessLog(order 10) after chain status=400 asyncStarted=false
12 REQUEST filter:raw(order 5) after chain
### POST /api/echo "hello body" X-Body-Mode=cache
HTTP 200 body=echo:hello body
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain POST /api/echo
03 REQUEST filter:body(order 30) CCRW before chain: getContentAsByteArray().length=0
04 REQUEST servlet:DispatcherServlet doDispatch start
05 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#echo
06 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#echo
07 REQUEST aspect:controller before HelloController#echo args=[hello body]
08 REQUEST controller echo received 10 chars
09 REQUEST aspect:controller after HelloController#echo returned=echo:hello body (String)
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST servlet:DispatcherServlet doDispatch end
15 REQUEST filter:body(order 30) CCRW after chain: getContentAsByteArray().length=10 -> "hello body"
16 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
17 REQUEST filter:raw(order 5) after chain
### POST /api/echo "hello body" X-Body-Mode=consume-wrapped
HTTP 400 body={"handled":"unreadable body"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain POST /api/echo
03 REQUEST filter:body(order 30) CCRW drained by the filter: 10 bytes read, getContentAsByteArray().length=10
04 REQUEST servlet:DispatcherServlet doDispatch start
05 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#echo
06 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#echo
07 REQUEST advice:@ExceptionHandler handling HttpMessageNotReadableException: Required request body is missing: public java.lang.String com.ankurm.filteraop.web.HelloController.echo(java.lang.String)
08 REQUEST interceptor:B afterCompletion ex=null
09 REQUEST interceptor:A afterCompletion ex=null
10 REQUEST servlet:DispatcherServlet doDispatch end
11 REQUEST filter:body(order 30) CCRW after chain: getContentAsByteArray().length=10 -> "hello body"
12 REQUEST filter:accessLog(order 10) after chain status=400 asyncStarted=false
13 REQUEST filter:raw(order 5) after chain
### POST /api/echo "hello body" X-Body-Mode=replay
HTTP 200 body=echo:hello body
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain POST /api/echo
03 REQUEST filter:body(order 30) own replayable wrapper: 10 bytes read up front
04 REQUEST servlet:DispatcherServlet doDispatch start
05 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#echo
06 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#echo
07 REQUEST aspect:controller before HelloController#echo args=[hello body]
08 REQUEST controller echo received 10 chars
09 REQUEST aspect:controller after HelloController#echo returned=echo:hello body (String)
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST servlet:DispatcherServlet doDispatch end
15 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
16 REQUEST filter:raw(order 5) after chain
### GET /api/hello/ankur X-Resp-Mode=copy (ContentCachingResponseWrapper)
HTTP 200 body=Hello, ankur Content-Length=12
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
06 REQUEST aspect:controller before HelloController#hello args=[ankur]
07 REQUEST controller hello(ankur)
08 REQUEST aspect:service before GreetingService#greet args=[ankur]
09 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
10 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
11 REQUEST interceptor:B postHandle status=200 modelAndView=null
12 REQUEST interceptor:A postHandle status=200 modelAndView=null
13 REQUEST interceptor:B afterCompletion ex=null
14 REQUEST interceptor:A afterCompletion ex=null
15 REQUEST servlet:DispatcherServlet doDispatch end
16 REQUEST filter:body(order 30) response wrapper holds 12 bytes
17 REQUEST filter:body(order 30) copyBodyToResponse() called
18 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
19 REQUEST filter:raw(order 5) after chain
### GET /api/hello/ankur X-Resp-Mode=forget (ContentCachingResponseWrapper)
HTTP 200 (empty body) Content-Length=0
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
06 REQUEST aspect:controller before HelloController#hello args=[ankur]
07 REQUEST controller hello(ankur)
08 REQUEST aspect:service before GreetingService#greet args=[ankur]
09 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
10 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
11 REQUEST interceptor:B postHandle status=200 modelAndView=null
12 REQUEST interceptor:A postHandle status=200 modelAndView=null
13 REQUEST interceptor:B afterCompletion ex=null
14 REQUEST interceptor:A afterCompletion ex=null
15 REQUEST servlet:DispatcherServlet doDispatch end
16 REQUEST filter:body(order 30) response wrapper holds 12 bytes
17 REQUEST filter:body(order 30) copyBodyToResponse() NOT called
18 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
19 REQUEST filter:raw(order 5) after chain
@@ -0,0 +1,26 @@
### GET /api/visibility/42: what each layer can see
HTTP 200 body={"id":42}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/visibility/42
03 REQUEST filter:visibility(order 25) before chain: method=GET uri=/api/visibility/42 X-Probe=hello handler attribute=null
04 REQUEST servlet:DispatcherServlet doDispatch start
05 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#visibility
06 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#visibility
07 REQUEST interceptor:visibility preHandle sees method=visibility params=[long] pathVars(raw strings)={id=42} pattern=/api/visibility/{id}
08 REQUEST interceptor:visibility preHandle: the converted argument and the return value are not available here
09 REQUEST aspect:controller before HelloController#visibility args=[42]
10 REQUEST aspect:visibility before arg[0]=42 (Long, already converted from the path string)
11 REQUEST aspect:visibility signature=HelloController.visibility(..) target=HelloController this=HelloController$$...
12 REQUEST aspect:visibility request reachable only through RequestContextHolder: GET /api/visibility/42
13 REQUEST controller visibility(42)
14 REQUEST aspect:visibility after returned=Item[id=42] (Item)
15 REQUEST aspect:controller after HelloController#visibility returned=Item[id=42] (Item)
16 REQUEST interceptor:visibility postHandle sees modelAndView=null (the @ResponseBody return value is not exposed)
17 REQUEST interceptor:B postHandle status=200 modelAndView=null
18 REQUEST interceptor:A postHandle status=200 modelAndView=null
19 REQUEST interceptor:B afterCompletion ex=null
20 REQUEST interceptor:A afterCompletion ex=null
21 REQUEST servlet:DispatcherServlet doDispatch end
22 REQUEST filter:visibility(order 25) after chain: handler attribute=HandlerMethod visibility pattern=/api/visibility/{id} status=200 Content-Type=application/json
23 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
24 REQUEST filter:raw(order 5) after chain
@@ -0,0 +1,24 @@
### GET /api/slow/80 (the service sleeps 80 ms)
HTTP 200 body=slept 80
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/slow/80
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#slow
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#slow
06 REQUEST aspect:controller before HelloController#slow args=[80]
07 REQUEST aspect:service before GreetingService#slow args=[80]
08 REQUEST aspect:service after GreetingService#slow returned=slept 80
09 REQUEST aspect:controller after HelloController#slow returned=slept 80 (String)
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST servlet:DispatcherServlet doDispatch end
15 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
16 REQUEST filter:raw(order 5) after chain
### Elapsed time seen by each layer, milliseconds (indicative: timing varies run to run)
filter (accessLog) 87 ms
interceptor (timing) 86 ms
aspect around controller 80 ms
aspect around service 80 ms
@@ -0,0 +1,20 @@
### GET /api/late/body: header set in preHandle and in postHandle
HTTP 200 body=late body
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/late/body
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#late
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#late
06 REQUEST aspect:controller before HelloController#late args=[]
07 REQUEST controller late() returning a String
08 REQUEST aspect:controller after HelloController#late returned=late body (String)
09 REQUEST interceptor:lateHeader postHandle response.isCommitted()=true
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST servlet:DispatcherServlet doDispatch end
15 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
16 REQUEST filter:raw(order 5) after chain
X-Added-In-PreHandle = yes
X-Added-In-PostHandle = null
@@ -0,0 +1,35 @@
### spring.web.resources.add-mappings=false, GET /nope
HTTP 404 body={"timestamp":"...","status":404,"error":"Not Found","path":"/nope"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /nope
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST servlet:DispatcherServlet doDispatch end
05 REQUEST filter:accessLog(order 10) after chain status=404 asyncStarted=false
06 REQUEST filter:raw(order 5) after chain
07 ERROR servlet:DispatcherServlet doDispatch start
08 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
09 ERROR interceptor:A error attributes: status=404 exception=null
10 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
11 ERROR interceptor:B postHandle status=404 modelAndView=null
12 ERROR interceptor:A postHandle status=404 modelAndView=null
13 ERROR interceptor:B afterCompletion ex=null
14 ERROR interceptor:A afterCompletion ex=null
15 ERROR servlet:DispatcherServlet doDispatch end
### same setting, GET /hello.txt (the file exists but nothing serves it)
HTTP 404 body={"timestamp":"...","status":404,"error":"Not Found","path":"/hello.txt"}
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /hello.txt
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST servlet:DispatcherServlet doDispatch end
05 REQUEST filter:accessLog(order 10) after chain status=404 asyncStarted=false
06 REQUEST filter:raw(order 5) after chain
07 ERROR servlet:DispatcherServlet doDispatch start
08 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
09 ERROR interceptor:A error attributes: status=404 exception=null
10 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
11 ERROR interceptor:B postHandle status=404 modelAndView=null
12 ERROR interceptor:A postHandle status=404 modelAndView=null
13 ERROR interceptor:B afterCompletion ex=null
14 ERROR interceptor:A afterCompletion ex=null
15 ERROR servlet:DispatcherServlet doDispatch end
@@ -0,0 +1,26 @@
### GET /api/hello/ankur with the naive (HandlerMethod) cast
HTTP 200 body=Hello, ankur
### GET /hello.txt with the naive cast
HTTP 500 body={"timestamp":"...","status":500,"error":"Internal Server Error","path":"/hello.txt"}
### Trace of the GET /hello.txt request (the last one run)
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /hello.txt
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=ResourceHttpRequestHandler
05 REQUEST interceptor:B preHandle handler=ResourceHttpRequestHandler
06 REQUEST interceptor:B afterCompletion ex=ClassCastException
07 REQUEST interceptor:A afterCompletion ex=ClassCastException
08 REQUEST servlet:DispatcherServlet doDispatch end
09 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
10 REQUEST filter:raw(order 5) after chain
11 ERROR servlet:DispatcherServlet doDispatch start
12 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
13 ERROR interceptor:A error attributes: status=500 exception=ServletException
14 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
15 ERROR interceptor:B postHandle status=500 modelAndView=null
16 ERROR interceptor:A postHandle status=500 modelAndView=null
17 ERROR interceptor:B afterCompletion ex=null
18 ERROR interceptor:A afterCompletion ex=null
19 ERROR servlet:DispatcherServlet doDispatch end
@@ -0,0 +1,22 @@
### Interceptors registered with addPathPatterns(...), one per pattern
/api/*
/api/**
/api/hello
/api/hello/*
/api/hello/**
/api/hello/{name}
/**
/error
### Which patterns fired (REQUEST dispatch) for each URL, and the HTTP status
/api/hello/ankur 200 [/api/**, /api/hello/*, /api/hello/**, /api/hello/{name}, /**] ERROR dispatch: []
/api/hello/ankur/ 404 [/api/**, /api/hello/**, /**] ERROR dispatch: [/**, /error]
/api/hello 404 [/api/*, /api/**, /api/hello, /api/hello/**, /**] ERROR dispatch: [/**, /error]
/api/hello/ 404 [/api/**, /api/hello/*, /api/hello/**, /**] ERROR dispatch: [/**, /error]
/api/ping 200 [/api/*, /api/**, /**] ERROR dispatch: []
/api/ping/ 404 [/api/**, /**] ERROR dispatch: [/**, /error]
/API/hello/ankur 404 [/**] ERROR dispatch: [/**, /error]
/api/hello/a/b 404 [/api/**, /api/hello/**, /**] ERROR dispatch: [/**, /error]
/api/hello/ankur.json 200 [/api/**, /api/hello/*, /api/hello/**, /api/hello/{name}, /**] ERROR dispatch: []
/api/hello/ankur;x=1 200 [/api/**, /api/hello/*, /api/hello/**, /api/hello/{name}, /**] ERROR dispatch: []
/nope 404 [/**] ERROR dispatch: [/**, /error]
@@ -0,0 +1,48 @@
### What the container injected for GreetingService
class = com.ankurm.filteraop.service.GreetingService$$SpringCGLIB$$N
isAopProxy = true
isCglib = true
### GET /api/hello/ankur (a normal call from the controller: the service aspect fires for greet)
HTTP 200 body=Hello, ankur
06 REQUEST aspect:controller before HelloController#hello args=[ankur]
07 REQUEST controller hello(ankur)
08 REQUEST aspect:service before GreetingService#greet args=[ankur]
09 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
10 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
### GET /api/twice/ankur (self-invocation: greetTwice calls this.greet() twice)
HTTP 200 body=Hello, ankur / Hello, ankur
06 REQUEST aspect:controller before HelloController#twice args=[ankur]
07 REQUEST aspect:service before GreetingService#greetTwice args=[ankur]
08 REQUEST aspect:service after GreetingService#greetTwice returned=Hello, ankur / Hello, ankur
09 REQUEST aspect:controller after HelloController#twice returned=Hello, ankur / Hello, ankur (String)
### GET /api/twice-fixed/ankur (the fix: FixedGreetingService calls greet() through an injected @Lazy reference to itself)
HTTP 200 body=Hello, ankur / Hello, ankur
06 REQUEST aspect:controller before HelloController#twiceFixed args=[ankur]
07 REQUEST aspect:service before FixedGreetingService#greetTwice args=[ankur]
08 REQUEST aspect:service before FixedGreetingService#greet args=[ankur]
09 REQUEST aspect:service after FixedGreetingService#greet returned=Hello, ankur
10 REQUEST aspect:service before FixedGreetingService#greet args=[ankur]
11 REQUEST aspect:service after FixedGreetingService#greet returned=Hello, ankur
12 REQUEST aspect:service after FixedGreetingService#greetTwice returned=Hello, ankur / Hello, ankur
13 REQUEST aspect:controller after HelloController#twiceFixed returned=Hello, ankur / Hello, ankur (String)
### GET /api/private/ankur (callsPrivate calls a private method)
HTTP 200 body=secret-ankur
06 REQUEST aspect:controller before HelloController#privateCall args=[ankur]
07 REQUEST aspect:service before GreetingService#callsPrivate args=[ankur]
08 REQUEST aspect:service after GreetingService#callsPrivate returned=secret-ankur
09 REQUEST aspect:controller after HelloController#privateCall returned=secret-ankur (String)
### GET /api/helper/ankur (usesHelper calls new Helper().shout(...))
HTTP 200 body=ANKUR!
06 REQUEST aspect:controller before HelloController#helper args=[ankur]
07 REQUEST aspect:service before GreetingService#usesHelper args=[ankur]
08 REQUEST aspect:service after GreetingService#usesHelper returned=ANKUR!
09 REQUEST aspect:controller after HelloController#helper returned=ANKUR! (String)
### Direct call on the proxy outside any web request: service.greetTwice("direct")
01 - aspect:service before GreetingService#greetTwice args=[direct]
02 - aspect:service after GreetingService#greetTwice returned=Hello, direct / Hello, direct
@@ -0,0 +1,59 @@
### Tomcat's filter chain with Spring Security 7.1.2 enabled
1 characterEncodingFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
2 formContentFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
3 earlyFilter [/*] [REQUEST]
4 requestContextFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
5 springSecurityFilterChain [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
6 rawFilter [/*] [REQUEST]
7 accessLog [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
8 apiKeyFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
9 visibilityFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
10 bodyFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
11 faultFilter [/*] [FORWARD, INCLUDE, REQUEST, ERROR, ASYNC]
12 twiceFilter [/*] [REQUEST]
13 Tomcat WebSocket (JSR356) Filter [/*] [FORWARD, REQUEST]
### Inside springSecurityFilterChain (FilterChainProxy.getFilterChains().get(0).getFilters()), in order
1 DisableEncodeUrlFilter
2 WebAsyncManagerIntegrationFilter
3 SecurityContextHolderFilter
4 HeaderWriterFilter
5 LogoutFilter
6 TwiceFilter
7 BasicAuthenticationFilter
8 RequestCacheAwareFilter
9 SecurityContextHolderAwareRequestFilter
10 AnonymousAuthenticationFilter
11 ExceptionTranslationFilter
12 AuthorizationFilter
### GET /api/hello/ankur with no credentials
HTTP 401 (empty body)
01 REQUEST filter:early(order -200) before chain
02 REQUEST filter:twice doFilter
03 REQUEST filter:early(order -200) after chain
04 ERROR filter:twice doFilter
### GET /api/hello/ankur as demo:demo
HTTP 200 body=Hello, ankur
01 REQUEST filter:early(order -200) before chain
02 REQUEST filter:twice doFilter
03 REQUEST filter:raw(order 5) before chain
04 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
05 REQUEST filter:twice doFilter
06 REQUEST servlet:DispatcherServlet doDispatch start
07 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
08 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
09 REQUEST aspect:controller before HelloController#hello args=[ankur]
10 REQUEST controller hello(ankur)
11 REQUEST aspect:service before GreetingService#greet args=[ankur]
12 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
13 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
14 REQUEST interceptor:B postHandle status=200 modelAndView=null
15 REQUEST interceptor:A postHandle status=200 modelAndView=null
16 REQUEST interceptor:B afterCompletion ex=null
17 REQUEST interceptor:A afterCompletion ex=null
18 REQUEST servlet:DispatcherServlet doDispatch end
19 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
20 REQUEST filter:raw(order 5) after chain
21 REQUEST filter:early(order -200) after chain
@@ -0,0 +1,24 @@
### A plain Filter bean that is also in the SecurityFilterChain: GET /api/hello/ankur
HTTP 200 body=Hello, ankur
01 REQUEST filter:early(order -200) before chain
02 REQUEST filter:twice doFilter
03 REQUEST filter:raw(order 5) before chain
04 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
05 REQUEST filter:twice doFilter
06 REQUEST servlet:DispatcherServlet doDispatch start
07 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
08 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
09 REQUEST aspect:controller before HelloController#hello args=[ankur]
10 REQUEST controller hello(ankur)
11 REQUEST aspect:service before GreetingService#greet args=[ankur]
12 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
13 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
14 REQUEST interceptor:B postHandle status=200 modelAndView=null
15 REQUEST interceptor:A postHandle status=200 modelAndView=null
16 REQUEST interceptor:B afterCompletion ex=null
17 REQUEST interceptor:A afterCompletion ex=null
18 REQUEST servlet:DispatcherServlet doDispatch end
19 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
20 REQUEST filter:raw(order 5) after chain
21 REQUEST filter:early(order -200) after chain
filter:twice ran 2 times for ONE request
@@ -0,0 +1,23 @@
### Same request with FilterRegistrationBean(enabled=false): GET /api/hello/ankur
HTTP 200 body=Hello, ankur
01 REQUEST filter:early(order -200) before chain
02 REQUEST filter:twice doFilter
03 REQUEST filter:raw(order 5) before chain
04 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
05 REQUEST servlet:DispatcherServlet doDispatch start
06 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
07 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
08 REQUEST aspect:controller before HelloController#hello args=[ankur]
09 REQUEST controller hello(ankur)
10 REQUEST aspect:service before GreetingService#greet args=[ankur]
11 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
12 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
13 REQUEST interceptor:B postHandle status=200 modelAndView=null
14 REQUEST interceptor:A postHandle status=200 modelAndView=null
15 REQUEST interceptor:B afterCompletion ex=null
16 REQUEST interceptor:A afterCompletion ex=null
17 REQUEST servlet:DispatcherServlet doDispatch end
18 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
19 REQUEST filter:raw(order 5) after chain
20 REQUEST filter:early(order -200) after chain
filter:twice ran 1 time(s) for ONE request
@@ -0,0 +1,112 @@
### Filters MockMvc will run (MockMvc.filters, outermost first)
OrderedCharacterEncodingFilter
OrderedFormContentFilter
OrderedRequestContextFilter
RawFilter
AccessLogFilter
ApiKeyFilter
VisibilityFilter
BodyFilter
FaultFilter
### GET /api/hello/ankur MockMvc: HTTP 200, 15 trace lines
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
03 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
04 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
05 REQUEST aspect:controller before HelloController#hello args=[ankur]
06 REQUEST controller hello(ankur)
07 REQUEST aspect:service before GreetingService#greet args=[ankur]
08 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
09 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
10 REQUEST interceptor:B postHandle status=200 modelAndView=null
11 REQUEST interceptor:A postHandle status=200 modelAndView=null
12 REQUEST interceptor:B afterCompletion ex=null
13 REQUEST interceptor:A afterCompletion ex=null
14 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
15 REQUEST filter:raw(order 5) after chain
### GET /api/hello/ankur real Tomcat: HTTP 200, 17 trace lines
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/hello/ankur
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#hello
05 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#hello
06 REQUEST aspect:controller before HelloController#hello args=[ankur]
07 REQUEST controller hello(ankur)
08 REQUEST aspect:service before GreetingService#greet args=[ankur]
09 REQUEST aspect:service after GreetingService#greet returned=Hello, ankur
10 REQUEST aspect:controller after HelloController#hello returned=Hello, ankur (String)
11 REQUEST interceptor:B postHandle status=200 modelAndView=null
12 REQUEST interceptor:A postHandle status=200 modelAndView=null
13 REQUEST interceptor:B afterCompletion ex=null
14 REQUEST interceptor:A afterCompletion ex=null
15 REQUEST servlet:DispatcherServlet doDispatch end
16 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
17 REQUEST filter:raw(order 5) after chain
### GET /nope MockMvc: HTTP 404, 8 trace lines
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /nope
03 REQUEST interceptor:A preHandle handler=ResourceHttpRequestHandler
04 REQUEST interceptor:B preHandle handler=ResourceHttpRequestHandler
05 REQUEST interceptor:B afterCompletion ex=null
06 REQUEST interceptor:A afterCompletion ex=null
07 REQUEST filter:accessLog(order 10) after chain status=404 asyncStarted=false
08 REQUEST filter:raw(order 5) after chain
### GET /nope real Tomcat: HTTP 404, 19 trace lines
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /nope
03 REQUEST servlet:DispatcherServlet doDispatch start
04 REQUEST interceptor:A preHandle handler=ResourceHttpRequestHandler
05 REQUEST interceptor:B preHandle handler=ResourceHttpRequestHandler
06 REQUEST interceptor:B afterCompletion ex=null
07 REQUEST interceptor:A afterCompletion ex=null
08 REQUEST servlet:DispatcherServlet doDispatch end
09 REQUEST filter:accessLog(order 10) after chain status=404 asyncStarted=false
10 REQUEST filter:raw(order 5) after chain
11 ERROR servlet:DispatcherServlet doDispatch start
12 ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error
13 ERROR interceptor:A error attributes: status=404 exception=null
14 ERROR interceptor:B preHandle handler=HandlerMethod BasicErrorController#error
15 ERROR interceptor:B postHandle status=404 modelAndView=null
16 ERROR interceptor:A postHandle status=404 modelAndView=null
17 ERROR interceptor:B afterCompletion ex=null
18 ERROR interceptor:A afterCompletion ex=null
19 ERROR servlet:DispatcherServlet doDispatch end
### GET /api/unhandled MockMvc: perform() THREW ServletException (cause UnsupportedOperationException)
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/unhandled
03 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#unhandled
04 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#unhandled
05 REQUEST aspect:controller before HelloController#unhandled args=[]
06 REQUEST controller unhandled() about to throw
07 REQUEST aspect:controller after HelloController#unhandled THREW UnsupportedOperationException
08 REQUEST interceptor:B afterCompletion ex=UnsupportedOperationException
09 REQUEST interceptor:A afterCompletion ex=UnsupportedOperationException
10 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=false
11 REQUEST filter:raw(order 5) after chain
### GET /api/async-callable MockMvc, after perform() and before asyncDispatch: asyncStarted=true
01 REQUEST filter:raw(order 5) before chain
02 REQUEST filter:accessLog(order 10) before chain GET /api/async-callable
03 REQUEST interceptor:A preHandle handler=HandlerMethod HelloController#asyncCallable
04 REQUEST interceptor:B preHandle handler=HandlerMethod HelloController#asyncCallable
05 REQUEST aspect:controller before HelloController#asyncCallable args=[]
06 REQUEST controller asyncCallable() returns a Callable
07 REQUEST aspect:controller after HelloController#asyncCallable returned=a lambda (HelloController$$Lambda)
08 REQUEST interceptor:B afterConcurrentHandlingStarted (async began, no postHandle/afterCompletion yet)
09 REQUEST interceptor:A afterConcurrentHandlingStarted (async began, no postHandle/afterCompletion yet)
10 REQUEST filter:accessLog(order 10) after chain status=200 asyncStarted=true
11 REQUEST filter:raw(order 5) after chain
12 REQUEST callable finished after 100 ms, returning
### ... then mvc.perform(MockMvcRequestBuilders.asyncDispatch(result))
01 ASYNC interceptor:A preHandle handler=HandlerMethod HelloController#asyncCallable
02 ASYNC interceptor:B preHandle handler=HandlerMethod HelloController#asyncCallable
03 ASYNC interceptor:B postHandle status=200 modelAndView=null
04 ASYNC interceptor:A postHandle status=200 modelAndView=null
05 ASYNC interceptor:B afterCompletion ex=null
06 ASYNC interceptor:A afterCompletion ex=null
@@ -0,0 +1,7 @@
spring-boot-starter-parent latest GA 4.1.2 newest listed 4.2.0-RC1
spring-boot-starter-aspectj latest GA 4.1.2 newest listed 4.2.0-RC1
spring-boot-starter-aop latest GA none newest listed 4.0.0-M2
spring-boot-starter-aop latest GA 3.5.16 newest listed 3.5.16
spring-webmvc latest GA 7.0.10 newest listed 7.1.0-RC1
spring-webmvc latest GA 6.2.19 newest listed 6.2.19
spring-security-web latest GA 7.1.2 newest listed 7.2.0-RC1
@@ -0,0 +1,43 @@
### Spring Framework 6.2.19
--- org.springframework.web.servlet.config.annotation.InterceptorRegistration
public InterceptorRegistration addPathPatterns(java.lang.String...);
public InterceptorRegistration addPathPatterns(java.util.List<java.lang.String>);
public InterceptorRegistration excludePathPatterns(java.lang.String...);
public InterceptorRegistration excludePathPatterns(java.util.List<java.lang.String>);
public InterceptorRegistration pathMatcher(PathMatcher);
public InterceptorRegistration order(int);
--- org.springframework.web.servlet.config.annotation.PathMatchConfigurer
public PathMatchConfigurer setPatternParser(PathPatternParser);
public PathMatchConfigurer setUseTrailingSlashMatch(java.lang.Boolean);
public PathMatchConfigurer setUseSuffixPatternMatch(java.lang.Boolean);
public PathMatchConfigurer setUseRegisteredSuffixPatternMatch(java.lang.Boolean);
public PathMatchConfigurer setUrlPathHelper(UrlPathHelper);
public PathMatchConfigurer setPathMatcher(PathMatcher);
--- org.springframework.web.util.pattern.PathPatternParser
public void setMatchOptionalTrailingSeparator(boolean);
public boolean isMatchOptionalTrailingSeparator();
public void setCaseSensitive(boolean);
public boolean isCaseSensitive();
public void setPathOptions(PathContainer$Options);
### Spring Framework 7.0.10
--- org.springframework.web.servlet.config.annotation.InterceptorRegistration
public InterceptorRegistration addPathPatterns(java.lang.String...);
public InterceptorRegistration addPathPatterns(java.util.List<java.lang.String>);
public InterceptorRegistration excludePathPatterns(java.lang.String...);
public InterceptorRegistration excludePathPatterns(java.util.List<java.lang.String>);
public InterceptorRegistration includeHttpMethods(HttpMethod...);
public InterceptorRegistration includeHttpMethods(java.util.List<HttpMethod>);
public InterceptorRegistration excludeHttpMethods(HttpMethod...);
public InterceptorRegistration excludeHttpMethods(java.util.List<HttpMethod>);
public InterceptorRegistration pathMatcher(PathMatcher);
public InterceptorRegistration order(int);
--- org.springframework.web.servlet.config.annotation.PathMatchConfigurer
public PathMatchConfigurer setPatternParser(PathPatternParser);
public PathMatchConfigurer setUrlPathHelper(UrlPathHelper);
public PathMatchConfigurer setPathMatcher(PathMatcher);
--- org.springframework.web.util.pattern.PathPatternParser
public void setCaseSensitive(boolean);
public boolean isCaseSensitive();
public void setPathOptions(PathContainer$Options);
@@ -0,0 +1,18 @@
### AbstractFilterRegistrationBean.determineDispatcherTypes (spring-boot-4.1.2.jar): the default dispatcher types
47: instanceof #93 // class org/springframework/web/filter/OncePerRequestFilter
55: invokestatic #97 // Method java/util/EnumSet.allOf:(Ljava/lang/Class;)Ljava/util/EnumSet;
59: getstatic #103 // Field jakarta/servlet/DispatcherType.REQUEST:Ljakarta/servlet/DispatcherType;
### DispatcherServletAutoConfiguration.DispatcherServletConfiguration (spring-boot-webmvc-4.1.2.jar)
13: invokevirtual #16 // Method org/springframework/web/servlet/DispatcherServlet.setDispatchOptionsRequest:(Z)V
21: invokevirtual #23 // Method org/springframework/web/servlet/DispatcherServlet.setDispatchTraceRequest:(Z)V
29: invokevirtual #29 // Method org/springframework/web/servlet/DispatcherServlet.setPublishEvents:(Z)V
37: invokevirtual #35 // Method org/springframework/web/servlet/DispatcherServlet.setEnableLoggingRequestDetails:(Z)V
name=["dispatcherServlet"]
### SecurityFilterProperties constants (spring-boot-security-4.1.2.jar)
public static final int BASIC_AUTH_ORDER = 2147483642;
public static final int DEFAULT_FILTER_ORDER = -100;
### MockMvc builds its own dispatcher servlet (spring-test-7.0.10.jar)
org/springframework/test/web/servlet/TestDispatcherServlet.class
+60
View File
@@ -0,0 +1,60 @@
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>4.1.2</version>
<relativePath/>
</parent>
<groupId>com.ankurm</groupId>
<artifactId>filter-interceptor-aop</artifactId>
<version>1.0.0</version>
<name>filter-interceptor-aop</name>
<description>Servlet Filter vs HandlerInterceptor vs Spring AOP in Spring Boot 4.1: the real order, what each can see, and the traps</description>
<properties>
<java.version>25</java.version>
</properties>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-webmvc</artifactId>
</dependency>
<!-- Boot 4 name. spring-boot-starter-aop has no 4.x release (last: 3.5.16). -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-aspectj</artifactId>
</dependency>
<!-- On the classpath for the "security" scenario only; switched off in application.properties. -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-security</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-webmvc-test</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
</dependency>
</dependencies>
<build>
<plugins>
<plugin>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-maven-plugin</artifactId>
</plugin>
</plugins>
</build>
</project>
+32
View File
@@ -0,0 +1,32 @@
#!/usr/bin/env bash
# Reads facts straight out of the jars in ~/.m2 (run `mvn test` or `mvn dependency:resolve` first).
# Writes output/22-boot-bytecode-facts.txt
set -eu
cd "$(dirname "$0")/.."
: "${JAVA_HOME:?set JAVA_HOME to JDK 25}"
M=${HOME}/.m2/repository
B=$M/org/springframework/boot
BV=4.1.2
SV=$(ls "$M/org/springframework/spring-test" | sort -V | tail -1)
W=$(mktemp -d)
OUT=output/22-boot-bytecode-facts.txt
javap_() { "$JAVA_HOME/bin/javap" "$@" 2>&1 | grep -v JAVA_TOOL_OPTIONS; }
{
echo "### AbstractFilterRegistrationBean.determineDispatcherTypes (spring-boot-$BV.jar): the default dispatcher types"
unzip -q -o "$B/spring-boot/$BV/spring-boot-$BV.jar" 'org/springframework/boot/web/servlet/AbstractFilterRegistrationBean*' -d "$W"
javap_ -p -c -cp "$W" org.springframework.boot.web.servlet.AbstractFilterRegistrationBean \
| awk '/determineDispatcherTypes/{f=1} /setDispatcherTypes/{f=0} f&&/(instanceof|allOf|DispatcherType.REQUEST)/{print}'
echo
echo "### DispatcherServletAutoConfiguration.DispatcherServletConfiguration (spring-boot-webmvc-$BV.jar)"
unzip -q -o "$B/spring-boot-webmvc/$BV/spring-boot-webmvc-$BV.jar" 'org/springframework/boot/webmvc/autoconfigure/DispatcherServletAutoConfiguration*' -d "$W"
javap_ -v -p -cp "$W" 'org.springframework.boot.webmvc.autoconfigure.DispatcherServletAutoConfiguration$DispatcherServletConfiguration' \
| grep -E 'name=\["dispatcherServlet"\]|invokevirtual.*(setDispatch|setPublish|setEnableLogging)' | sed -E 's/^ +//'
echo
echo "### SecurityFilterProperties constants (spring-boot-security-$BV.jar)"
unzip -q -o "$B/spring-boot-security/$BV/spring-boot-security-$BV.jar" 'org/springframework/boot/security/autoconfigure/web/servlet/SecurityFilterProperties.class' -d "$W"
javap_ -p -constants -cp "$W" org.springframework.boot.security.autoconfigure.web.servlet.SecurityFilterProperties | grep static
echo
echo "### MockMvc builds its own dispatcher servlet (spring-test-$SV.jar)"
unzip -l "$M/org/springframework/spring-test/$SV/spring-test-$SV.jar" | grep -E 'servlet/TestDispatcherServlet.class' | awk '{print $4}'
} > "$OUT"
cat "$OUT"
+30
View File
@@ -0,0 +1,30 @@
#!/usr/bin/env bash
# Reads maven-metadata.xml from Maven Central (authoritative; the solrsearch API is stale from some networks).
# Writes output/20-central-versions.txt
set -eu
cd "$(dirname "$0")/.."
OUT=output/20-central-versions.txt
mkdir -p output
: > "$OUT"
latest() {
local group=$1 artifact=$2 filter=${3:-.}
local xml
for i in 1 2 3 4 5; do
xml=$(curl -sf "https://repo1.maven.org/maven2/${group}/${artifact}/maven-metadata.xml") && break || sleep 20
done
local all
all=$(echo "$xml" | tr '<' '\n' | grep '^version>' | sed 's/^version>//' | grep -E "$filter")
local ga
ga=$(echo "$all" | grep -vE -- '-M|-RC|-SNAPSHOT|-alpha|-beta' | tail -1)
local newest
newest=$(echo "$all" | tail -1)
printf '%-34s latest GA %-10s newest listed %s\n' "$artifact" "${ga:-none}" "${newest:-none}" >> "$OUT"
}
latest org/springframework/boot spring-boot-starter-parent '^4\.'
latest org/springframework/boot spring-boot-starter-aspectj '^4\.'
latest org/springframework/boot spring-boot-starter-aop '^4\.'
latest org/springframework/boot spring-boot-starter-aop '^3\.'
latest org/springframework spring-webmvc '^7\.'
latest org/springframework spring-webmvc '^6\.2\.'
latest org/springframework/security spring-security-web '^7\.'
cat "$OUT"
+34
View File
@@ -0,0 +1,34 @@
#!/usr/bin/env bash
# javap of the same four classes in Spring Framework 6.2.19 and 7.0.10, to show what changed for
# interceptor registration and path matching. Writes output/21-framework-6.2-vs-7.0.txt
set -eu
cd "$(dirname "$0")/.."
: "${JAVA_HOME:?set JAVA_HOME to a JDK}"
W=$(mktemp -d)
OUT=output/21-framework-6.2-vs-7.0.txt
mkdir -p output
fetch() { # group artifact version
local f="$W/$2-$3.jar"
for i in 1 2 3 4 5; do
curl -sf -o "$f" "https://repo1.maven.org/maven2/$1/$2/$3/$2-$3.jar" && unzip -tq "$f" >/dev/null 2>&1 && return 0
sleep 20
done
echo "could not fetch $2 $3" >&2; return 1
}
: > "$OUT"
for V in 6.2.19 7.0.10; do
fetch org/springframework spring-web "$V"
fetch org/springframework spring-webmvc "$V"
CP="$W/spring-webmvc-$V.jar:$W/spring-web-$V.jar"
{
echo "### Spring Framework $V"
for c in org.springframework.web.servlet.config.annotation.InterceptorRegistration \
org.springframework.web.servlet.config.annotation.PathMatchConfigurer \
org.springframework.web.util.pattern.PathPatternParser; do
echo "--- $c"
"$JAVA_HOME/bin/javap" -cp "$CP" "$c" 2>&1 | grep -E '^ public' | grep -E 'InterceptorRegistration [a-z]|PathMatchConfigurer set|PathPatternParser|void set|boolean is' | sed -E 's/org\.springframework\.[a-z.]*\.//g' | grep -vE 'getPattern|getUrlPath|getPathM|Parser\(\)|defaultInstance'
done
echo
} >> "$OUT"
done
cat "$OUT"
+11
View File
@@ -0,0 +1,11 @@
#!/usr/bin/env bash
# Regenerates every file in output/. The tests write the transcripts and assert the same facts.
# 20-* and 21-* come from scripts that read Maven Central (network); 22-* reads the jars in ~/.m2.
set -eu
cd "$(dirname "$0")/.."
: "${JAVA_HOME:?set JAVA_HOME to JDK 25}"
mvn -B -q test
./scripts/central-versions.sh
./scripts/framework-diff.sh
./scripts/boot-facts.sh
ls output
+8
View File
@@ -0,0 +1,8 @@
#!/usr/bin/env bash
# Starts the demo app on :8080. Add the "security" profile to put Spring Security 7 in front of everything.
# ./scripts/run.sh plain
# ./scripts/run.sh security HTTP Basic demo:demo
set -eu
cd "$(dirname "$0")/.."
PROFILE="${1:-}"
exec mvn -B -q spring-boot:run ${PROFILE:+-Dspring-boot.run.profiles=$PROFILE}
@@ -0,0 +1,11 @@
package com.ankurm.filteraop;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
@SpringBootApplication
public class FilterAopApplication {
public static void main(String[] args) {
SpringApplication.run(FilterAopApplication.class, args);
}
}
@@ -0,0 +1,39 @@
package com.ankurm.filteraop.aop;
import com.ankurm.filteraop.trace.Trace;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
/** Wraps every @RestController method in com.ankurm.filteraop.web. It sees arguments and the return value. */
@Aspect
@Component
@Order(1)
public class ControllerAspect {
private final Trace trace;
public ControllerAspect(Trace trace) {
this.trace = trace;
}
@Around("@within(org.springframework.web.bind.annotation.RestController) && within(com.ankurm.filteraop.web..*) && !execution(* com.ankurm.filteraop.web.DiagController.*(..))")
public Object aroundController(ProceedingJoinPoint pjp) throws Throwable {
String method = pjp.getSignature().getDeclaringType().getSimpleName() + "#" + pjp.getSignature().getName();
trace.log("aspect:controller", "before " + method + " args=" + Summaries.of(pjp.getArgs()));
long start = System.nanoTime();
try {
Object result = pjp.proceed();
trace.log("aspect:controller", "after " + method + " returned=" + Summaries.of(result)
+ " (" + (result == null ? "null" : result.getClass().getSimpleName().replaceAll("/0x[0-9a-f]+", "")) + ")");
return result;
} catch (Throwable t) {
trace.log("aspect:controller", "after " + method + " THREW " + t.getClass().getSimpleName());
throw t;
} finally {
trace.record("aspect:controller", System.nanoTime() - start);
}
}
}
@@ -0,0 +1,41 @@
package com.ankurm.filteraop.aop;
import com.ankurm.filteraop.trace.Trace;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
/**
* Matches by signature: every method of every type in the service package. It only fires for
* calls that go through the Spring proxy; see GreetingService for the three that do not.
*/
@Aspect
@Component
@Order(2)
public class ServiceAspect {
private final Trace trace;
public ServiceAspect(Trace trace) {
this.trace = trace;
}
@Around("execution(* com.ankurm.filteraop.service..*(..))")
public Object aroundService(ProceedingJoinPoint pjp) throws Throwable {
String method = pjp.getSignature().getDeclaringType().getSimpleName() + "#" + pjp.getSignature().getName();
trace.log("aspect:service", "before " + method + " args=" + Summaries.of(pjp.getArgs()));
long start = System.nanoTime();
try {
Object result = pjp.proceed();
trace.log("aspect:service", "after " + method + " returned=" + Summaries.of(result));
return result;
} catch (Throwable t) {
trace.log("aspect:service", "after " + method + " THREW " + t.getClass().getSimpleName());
throw t;
} finally {
trace.record("aspect:service", System.nanoTime() - start);
}
}
}
@@ -0,0 +1,23 @@
package com.ankurm.filteraop.aop;
import java.util.Arrays;
final class Summaries {
private Summaries() {
}
static String of(Object o) {
if (o == null) {
return "null";
}
if (o.getClass().isSynthetic() || o.getClass().isHidden() || o.getClass().getName().contains("$$Lambda")) {
return "a lambda";
}
String s = o.getClass().isArray() ? Arrays.deepToString((Object[]) o) : String.valueOf(o);
if (s.matches("(?s).*@[0-9a-f]{4,}.*")) {
return "an instance of " + o.getClass().getSimpleName();
}
s = s.replace("\n", "\\n");
return s.length() > 60 ? s.substring(0, 57) + "..." : s;
}
}
@@ -0,0 +1,38 @@
package com.ankurm.filteraop.aop;
import com.ankurm.filteraop.trace.Trace;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
/** What an aspect can see: the converted argument, the return value, the signature; not the HandlerMethod. */
@Aspect
@Component
@Order(3)
public class VisibilityAspect {
private final Trace trace;
public VisibilityAspect(Trace trace) {
this.trace = trace;
}
@Around("execution(* com.ankurm.filteraop.web.HelloController.visibility(..))")
public Object probe(ProceedingJoinPoint pjp) throws Throwable {
Object arg = pjp.getArgs()[0];
trace.log("aspect:visibility", "before arg[0]=" + arg + " (" + arg.getClass().getSimpleName()
+ ", already converted from the path string)");
trace.log("aspect:visibility", "signature=" + pjp.getSignature().toShortString()
+ " target=" + pjp.getTarget().getClass().getSimpleName() + " this=" + pjp.getThis().getClass().getSimpleName().replaceAll("\\$\\$.*", "\\$\\$..."));
var attrs = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
trace.log("aspect:visibility", "request reachable only through RequestContextHolder: "
+ attrs.getRequest().getMethod() + " " + attrs.getRequest().getRequestURI());
Object result = pjp.proceed();
trace.log("aspect:visibility", "after returned=" + result + " (" + result.getClass().getSimpleName() + ")");
return result;
}
}
@@ -0,0 +1,39 @@
package com.ankurm.filteraop.filter;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.filter.OncePerRequestFilter;
import java.io.IOException;
/**
* A OncePerRequestFilter registered through a FilterRegistrationBean (see FilterConfig), order 10.
* Logs the status and the time the whole request took, the classic access-log filter.
*/
public class AccessLogFilter extends OncePerRequestFilter {
private final Trace trace;
private final String name;
public AccessLogFilter(Trace trace, String name) {
this.trace = trace;
this.name = name;
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
throws ServletException, IOException {
trace.log(request, "filter:" + name, "before chain " + request.getMethod() + " " + request.getRequestURI());
long start = System.nanoTime();
try {
chain.doFilter(request, response);
} finally {
trace.record("filter:" + name, System.nanoTime() - start);
trace.log(request, "filter:" + name,
"after chain status=" + response.getStatus() + " asyncStarted=" + request.isAsyncStarted());
}
}
}
@@ -0,0 +1,43 @@
package com.ankurm.filteraop.filter;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;
import java.io.IOException;
/** Authentication example: /api/secure/** needs X-Api-Key. A rejection is written here and the chain stops. */
@Component
@Order(20)
public class ApiKeyFilter extends OncePerRequestFilter {
private final Trace trace;
public ApiKeyFilter(Trace trace) {
this.trace = trace;
}
@Override
protected boolean shouldNotFilter(HttpServletRequest request) {
return !request.getRequestURI().startsWith("/api/secure/");
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
throws ServletException, IOException {
if (!"demo-key".equals(request.getHeader("X-Api-Key"))) {
trace.log(request, "filter:apiKey(order 20)", "REJECT 401, chain stops here");
response.setStatus(HttpServletResponse.SC_UNAUTHORIZED);
response.setContentType("application/json");
response.getWriter().write("{\"error\":\"missing or wrong X-Api-Key\"}");
return;
}
trace.log(request, "filter:apiKey(order 20)", "key ok, continue");
chain.doFilter(request, response);
}
}
@@ -0,0 +1,92 @@
package com.ankurm.filteraop.filter;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.ContentCachingResponseWrapper;
import java.io.IOException;
import java.nio.charset.StandardCharsets;
/**
* The request-body-read-twice problem, in five selectable shapes (header X-Body-Mode), plus the
* response-wrapper mistake (header X-Resp-Mode). Without either header it does nothing.
*/
@Component
@Order(30)
public class BodyFilter extends OncePerRequestFilter {
private static final String WHO = "filter:body(order 30)";
private final Trace trace;
public BodyFilter(Trace trace) {
this.trace = trace;
}
@Override
protected boolean shouldNotFilter(HttpServletRequest request) {
return request.getHeader("X-Body-Mode") == null && request.getHeader("X-Resp-Mode") == null;
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
throws ServletException, IOException {
String mode = request.getHeader("X-Body-Mode");
String respMode = request.getHeader("X-Resp-Mode");
HttpServletRequest forward = request;
if ("consume".equals(mode)) {
// MISTAKE 1: read the raw stream, hand the same request on.
byte[] bytes = request.getInputStream().readAllBytes();
trace.log(request, WHO, "read raw stream: " + bytes.length + " bytes, passing the ORIGINAL request on");
} else if ("cache".equals(mode)) {
// ContentCachingRequestWrapper caches only what is read through it, later.
ContentCachingRequestWrapper wrapper = new ContentCachingRequestWrapper(request, 1024);
trace.log(request, WHO, "CCRW before chain: getContentAsByteArray().length=" + wrapper.getContentAsByteArray().length);
forward = wrapper;
} else if ("consume-wrapped".equals(mode)) {
// MISTAKE 2: wrapper, but the filter itself drains it before the chain.
ContentCachingRequestWrapper wrapper = new ContentCachingRequestWrapper(request, 1024);
byte[] bytes = wrapper.getInputStream().readAllBytes();
trace.log(request, WHO, "CCRW drained by the filter: " + bytes.length
+ " bytes read, getContentAsByteArray().length=" + wrapper.getContentAsByteArray().length);
forward = wrapper;
} else if ("replay".equals(mode)) {
CachedBodyRequest replay = new CachedBodyRequest(request);
trace.log(request, WHO, "own replayable wrapper: " + replay.body().length + " bytes read up front");
forward = replay;
}
HttpServletResponse out = response;
ContentCachingResponseWrapper respWrapper = null;
if (respMode != null) {
respWrapper = new ContentCachingResponseWrapper(response);
out = respWrapper;
}
try {
chain.doFilter(forward, out);
} finally {
if (forward instanceof ContentCachingRequestWrapper ccrw) {
trace.log(request, WHO, "CCRW after chain: getContentAsByteArray().length="
+ ccrw.getContentAsByteArray().length + " -> \""
+ new String(ccrw.getContentAsByteArray(), StandardCharsets.UTF_8) + "\"");
}
if (respWrapper != null) {
trace.log(request, WHO, "response wrapper holds " + respWrapper.getContentSize() + " bytes");
if ("copy".equals(respMode)) {
respWrapper.copyBodyToResponse();
trace.log(request, WHO, "copyBodyToResponse() called");
} else {
trace.log(request, WHO, "copyBodyToResponse() NOT called");
}
}
}
}
}
@@ -0,0 +1,57 @@
package com.ankurm.filteraop.filter;
import jakarta.servlet.ReadListener;
import jakarta.servlet.ServletInputStream;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletRequestWrapper;
import java.io.BufferedReader;
import java.io.ByteArrayInputStream;
import java.io.IOException;
import java.io.InputStreamReader;
/** A request whose body can be read any number of times: the bytes are read once, up front. */
public class CachedBodyRequest extends HttpServletRequestWrapper {
private final byte[] body;
public CachedBodyRequest(HttpServletRequest request) throws IOException {
super(request);
this.body = request.getInputStream().readAllBytes();
}
public byte[] body() {
return body;
}
@Override
public ServletInputStream getInputStream() {
ByteArrayInputStream in = new ByteArrayInputStream(body);
return new ServletInputStream() {
@Override
public boolean isFinished() {
return in.available() == 0;
}
@Override
public boolean isReady() {
return true;
}
@Override
public void setReadListener(ReadListener listener) {
throw new UnsupportedOperationException();
}
@Override
public int read() {
return in.read();
}
};
}
@Override
public BufferedReader getReader() {
return new BufferedReader(new InputStreamReader(getInputStream(), java.nio.charset.StandardCharsets.UTF_8));
}
}
@@ -0,0 +1,36 @@
package com.ankurm.filteraop.filter;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;
import java.io.IOException;
/** Throws when asked to (X-Filter-Throw), to show that @ControllerAdvice never sees a filter's exception. */
@Component
@Order(40)
public class FaultFilter extends OncePerRequestFilter {
private final Trace trace;
public FaultFilter(Trace trace) {
this.trace = trace;
}
@Override
protected boolean shouldNotFilter(HttpServletRequest request) {
return request.getHeader("X-Filter-Throw") == null;
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
throws ServletException, IOException {
trace.log(request, "filter:fault(order 40)", "throwing IllegalStateException");
throw new IllegalStateException("thrown from a filter");
}
}
@@ -0,0 +1,23 @@
package com.ankurm.filteraop.filter;
import com.ankurm.filteraop.trace.Trace;
import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
@Configuration
public class FilterConfig {
/**
* A OncePerRequestFilter wired through a FilterRegistrationBean. The order lives on the
* registration, not on the filter class. 10 sits between RawFilter (@Order 5) and ApiKeyFilter (@Order 20).
*/
@Bean
FilterRegistrationBean<AccessLogFilter> accessLogFilter(Trace trace) {
FilterRegistrationBean<AccessLogFilter> reg = new FilterRegistrationBean<>(new AccessLogFilter(trace, "accessLog(order 10)"));
reg.setName("accessLog");
reg.setOrder(10);
reg.addUrlPatterns("/*");
return reg;
}
}
@@ -0,0 +1,40 @@
package com.ankurm.filteraop.filter;
import com.ankurm.filteraop.trace.Trace;
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 org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import java.io.IOException;
/**
* A plain jakarta.servlet.Filter: not OncePerRequestFilter. Boot registers a bean like this for
* DispatcherType.REQUEST only. Ordered with @Order, no FilterRegistrationBean involved.
*/
@Component
@Order(5)
public class RawFilter implements Filter {
private final Trace trace;
public RawFilter(Trace trace) {
this.trace = trace;
}
@Override
public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain)
throws IOException, ServletException {
HttpServletRequest request = (HttpServletRequest) req;
trace.log(request, "filter:raw(order 5)", "before chain");
try {
chain.doFilter(req, res);
} finally {
trace.log(request, "filter:raw(order 5)", "after chain");
}
}
}
@@ -0,0 +1,45 @@
package com.ankurm.filteraop.filter;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.servlet.HandlerMapping;
import java.io.IOException;
/** Prints what a servlet filter can and cannot see: the raw request, the response, and (only afterwards) the handler. */
@Component
@Order(25)
public class VisibilityFilter extends OncePerRequestFilter {
private final Trace trace;
public VisibilityFilter(Trace trace) {
this.trace = trace;
}
@Override
protected boolean shouldNotFilter(HttpServletRequest request) {
return !request.getRequestURI().startsWith("/api/visibility/");
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
throws ServletException, IOException {
trace.log(request, "filter:visibility(order 25)", "before chain: method=" + request.getMethod()
+ " uri=" + request.getRequestURI() + " X-Probe=" + request.getHeader("X-Probe")
+ " handler attribute=" + request.getAttribute(HandlerMapping.BEST_MATCHING_HANDLER_ATTRIBUTE));
chain.doFilter(request, response);
Object handler = request.getAttribute(HandlerMapping.BEST_MATCHING_HANDLER_ATTRIBUTE);
trace.log(request, "filter:visibility(order 25)", "after chain: handler attribute="
+ (handler instanceof HandlerMethod hm ? "HandlerMethod " + hm.getMethod().getName() : handler)
+ " pattern=" + request.getAttribute(HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE)
+ " status=" + response.getStatus() + " Content-Type=" + response.getContentType());
}
}
@@ -0,0 +1,38 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.servlet.HandlerInterceptor;
import java.io.IOException;
/**
* preHandle returns false. With ?mode=write it also writes a 403 body; with ?mode=silent it
* returns false and writes nothing, which is the classic way to send an empty 200.
*/
public class GateInterceptor implements HandlerInterceptor {
private final Trace trace;
public GateInterceptor(Trace trace) {
this.trace = trace;
}
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
throws IOException {
String mode = request.getParameter("mode");
if (mode == null) {
trace.log(request, "interceptor:gate", "preHandle -> true");
return true;
}
trace.log(request, "interceptor:gate", "preHandle -> FALSE (mode=" + mode + ")");
if ("write".equals(mode)) {
response.setStatus(HttpServletResponse.SC_FORBIDDEN);
response.setContentType("application/json");
response.getWriter().write("{\"error\":\"gate closed\"}");
}
return false;
}
}
@@ -0,0 +1,16 @@
package com.ankurm.filteraop.interceptor;
import org.springframework.web.method.HandlerMethod;
final class Handlers {
private Handlers() {
}
/** What the interceptor was handed: a HandlerMethod for @RequestMapping methods, something else otherwise. */
static String describe(Object handler) {
if (handler instanceof HandlerMethod hm) {
return "HandlerMethod " + hm.getBeanType().getSimpleName() + "#" + hm.getMethod().getName();
}
return handler.getClass().getSimpleName();
}
}
@@ -0,0 +1,30 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;
/** Tries to add a response header in postHandle, which runs after the controller has already written the body. */
public class LateHeaderInterceptor implements HandlerInterceptor {
private final Trace trace;
public LateHeaderInterceptor(Trace trace) {
this.trace = trace;
}
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
response.setHeader("X-Added-In-PreHandle", "yes");
return true;
}
@Override
public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler,
ModelAndView modelAndView) {
trace.log(request, "interceptor:lateHeader", "postHandle response.isCommitted()=" + response.isCommitted());
response.setHeader("X-Added-In-PostHandle", "yes");
}
}
@@ -0,0 +1,16 @@
package com.ankurm.filteraop.interceptor;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.HandlerInterceptor;
/** The mistake: assume the handler is always a HandlerMethod. Enabled only with demo.naive-interceptor=true. */
public class NaiveCastInterceptor implements HandlerInterceptor {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
HandlerMethod hm = (HandlerMethod) handler;
return hm.getMethod() != null;
}
}
@@ -0,0 +1,39 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
/** One interceptor per path pattern, each logging only its own name: shows which patterns match which URL. */
@Configuration
@ConditionalOnProperty("demo.pattern-probe")
public class PatternProbeConfig implements WebMvcConfigurer {
public static final String[] PATTERNS = {
"/api/*", "/api/**", "/api/hello", "/api/hello/*", "/api/hello/**", "/api/hello/{name}", "/**", "/error"
};
private final Trace trace;
public PatternProbeConfig(Trace trace) {
this.trace = trace;
}
@Override
public void addInterceptors(InterceptorRegistry registry) {
for (String pattern : PATTERNS) {
registry.addInterceptor(new HandlerInterceptor() {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
trace.log(request, "probe", pattern);
return true;
}
}).addPathPatterns(pattern);
}
}
}
@@ -0,0 +1,13 @@
package com.ankurm.filteraop.interceptor;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
/** Marker the RoleInterceptor looks for on the handler method. */
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface RequiresRole {
String value();
}
@@ -0,0 +1,42 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.HandlerInterceptor;
import java.io.IOException;
/**
* Authorisation example: only an interceptor can read @RequiresRole off the handler method before
* the method runs. Note the instanceof check: static resources get a ResourceHttpRequestHandler.
*/
public class RoleInterceptor implements HandlerInterceptor {
private final Trace trace;
public RoleInterceptor(Trace trace) {
this.trace = trace;
}
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
throws IOException {
if (!(handler instanceof HandlerMethod hm)) {
return true;
}
RequiresRole required = hm.getMethodAnnotation(RequiresRole.class);
if (required == null) {
return true;
}
String role = request.getHeader("X-Role");
boolean ok = required.value().equals(role);
trace.log(request, "interceptor:role", "@RequiresRole(\"" + required.value() + "\") on "
+ hm.getMethod().getName() + ", X-Role=" + role + " -> " + (ok ? "allow" : "deny 403"));
if (!ok) {
response.sendError(HttpServletResponse.SC_FORBIDDEN, "role " + required.value() + " required");
}
return ok;
}
}
@@ -0,0 +1,32 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.servlet.HandlerInterceptor;
/** Timing example: elapsed time from preHandle to afterCompletion, kept in a request attribute. */
public class TimingInterceptor implements HandlerInterceptor {
private static final String START = TimingInterceptor.class.getName() + ".start";
private final Trace trace;
public TimingInterceptor(Trace trace) {
this.trace = trace;
}
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
request.setAttribute(START, System.nanoTime());
return true;
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler,
Exception ex) {
Long start = (Long) request.getAttribute(START);
if (start != null) {
trace.record("interceptor:timing", System.nanoTime() - start);
}
}
}
@@ -0,0 +1,53 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.servlet.AsyncHandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;
/** Logs every callback. An AsyncHandlerInterceptor, so afterConcurrentHandlingStarted is visible too. */
public class TraceInterceptor implements AsyncHandlerInterceptor {
private final Trace trace;
private final String name;
public TraceInterceptor(Trace trace, String name) {
this.trace = trace;
this.name = name;
}
private String who() {
return "interceptor:" + name;
}
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
trace.log(request, who(), "preHandle handler=" + Handlers.describe(handler));
if (request.getDispatcherType() == jakarta.servlet.DispatcherType.ERROR && "A".equals(name)) {
Object ex = request.getAttribute(jakarta.servlet.RequestDispatcher.ERROR_EXCEPTION);
trace.log(request, who(), " error attributes: status=" + request.getAttribute(jakarta.servlet.RequestDispatcher.ERROR_STATUS_CODE)
+ " exception=" + (ex == null ? "null" : ex.getClass().getSimpleName()));
}
return true;
}
@Override
public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler,
ModelAndView modelAndView) {
trace.log(request, who(), "postHandle status=" + response.getStatus() + " modelAndView="
+ (modelAndView == null ? "null" : "present"));
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler,
Exception ex) {
trace.log(request, who(), "afterCompletion ex=" + (ex == null ? "null" : ex.getClass().getSimpleName()));
}
@Override
public void afterConcurrentHandlingStarted(HttpServletRequest request, HttpServletResponse response,
Object handler) {
trace.log(request, who(), "afterConcurrentHandlingStarted (async began, no postHandle/afterCompletion yet)");
}
}
@@ -0,0 +1,42 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.HandlerMapping;
import org.springframework.web.servlet.ModelAndView;
import java.util.Arrays;
import java.util.Map;
/** Prints what a HandlerInterceptor can and cannot see about the call that is about to be made. */
public class VisibilityInterceptor implements HandlerInterceptor {
private final Trace trace;
public VisibilityInterceptor(Trace trace) {
this.trace = trace;
}
@Override
@SuppressWarnings("unchecked")
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
HandlerMethod hm = (HandlerMethod) handler;
Map<String, String> vars = (Map<String, String>) request.getAttribute(HandlerMapping.URI_TEMPLATE_VARIABLES_ATTRIBUTE);
trace.log(request, "interceptor:visibility", "preHandle sees method=" + hm.getMethod().getName()
+ " params=" + Arrays.toString(Arrays.stream(hm.getMethodParameters()).map(p -> p.getParameterType().getSimpleName()).toArray())
+ " pathVars(raw strings)=" + vars
+ " pattern=" + request.getAttribute(HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE));
trace.log(request, "interceptor:visibility", "preHandle: the converted argument and the return value are not available here");
return true;
}
@Override
public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler,
ModelAndView modelAndView) {
trace.log(request, "interceptor:visibility", "postHandle sees modelAndView="
+ (modelAndView == null ? "null" : "present") + " (the @ResponseBody return value is not exposed)");
}
}
@@ -0,0 +1,36 @@
package com.ankurm.filteraop.interceptor;
import com.ankurm.filteraop.trace.Trace;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
/**
* Registration order is execution order for preHandle (and the reverse for postHandle and
* afterCompletion) unless .order(n) is used.
*/
@Configuration
public class WebConfig implements WebMvcConfigurer {
private final Trace trace;
private final boolean naive;
public WebConfig(Trace trace, @org.springframework.beans.factory.annotation.Value("${demo.naive-interceptor:false}") boolean naive) {
this.trace = trace;
this.naive = naive;
}
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(new TraceInterceptor(trace, "A")).addPathPatterns("/**").excludePathPatterns("/diag/**");
registry.addInterceptor(new GateInterceptor(trace)).addPathPatterns("/api/gated/**");
registry.addInterceptor(new TraceInterceptor(trace, "B")).addPathPatterns("/**").excludePathPatterns("/diag/**");
registry.addInterceptor(new RoleInterceptor(trace)).addPathPatterns("/api/**");
registry.addInterceptor(new TimingInterceptor(trace)).addPathPatterns("/api/**");
registry.addInterceptor(new LateHeaderInterceptor(trace)).addPathPatterns("/api/late/**");
registry.addInterceptor(new VisibilityInterceptor(trace)).addPathPatterns("/api/visibility/**");
if (naive) {
registry.addInterceptor(new NaiveCastInterceptor()).addPathPatterns("/**");
}
}
}
@@ -0,0 +1,88 @@
package com.ankurm.filteraop.security;
import com.ankurm.filteraop.trace.Trace;
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 org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Profile;
import org.springframework.security.config.Customizer;
import org.springframework.security.config.annotation.web.builders.HttpSecurity;
import org.springframework.security.web.SecurityFilterChain;
import org.springframework.security.web.authentication.www.BasicAuthenticationFilter;
import java.io.IOException;
/** Only active with the "security" profile. Spring Security 7.1.2 on Boot 4.1.2. */
@Configuration
@Profile("security")
public class SecurityDemoConfig {
/** A servlet filter that is ALSO added to the Security chain: the double-registration trap. */
static class TwiceFilter implements Filter {
private final Trace trace;
TwiceFilter(Trace trace) {
this.trace = trace;
}
@Override
public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain)
throws IOException, ServletException {
trace.log((HttpServletRequest) req, "filter:twice", "doFilter");
chain.doFilter(req, res);
}
}
/** Order -200: before springSecurityFilterChain (-100), so it sees requests Security will reject. */
static class EarlyFilter implements Filter {
private final Trace trace;
EarlyFilter(Trace trace) {
this.trace = trace;
}
@Override
public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain)
throws IOException, ServletException {
trace.log((HttpServletRequest) req, "filter:early(order -200)", "before chain");
chain.doFilter(req, res);
trace.log((HttpServletRequest) req, "filter:early(order -200)", "after chain");
}
}
@Bean
TwiceFilter twiceFilter(Trace trace) {
return new TwiceFilter(trace);
}
/** Fix for the double run: keep the bean, stop Boot registering it with the container. */
@Bean
@org.springframework.boot.autoconfigure.condition.ConditionalOnProperty("demo.twice.fix")
FilterRegistrationBean<TwiceFilter> twiceFilterRegistration(TwiceFilter twiceFilter) {
FilterRegistrationBean<TwiceFilter> reg = new FilterRegistrationBean<>(twiceFilter);
reg.setEnabled(false);
return reg;
}
@Bean
FilterRegistrationBean<EarlyFilter> earlyFilter(Trace trace) {
FilterRegistrationBean<EarlyFilter> reg = new FilterRegistrationBean<>(new EarlyFilter(trace));
reg.setOrder(-200);
return reg;
}
@Bean
SecurityFilterChain securityFilterChain(HttpSecurity http, TwiceFilter twiceFilter) {
http.authorizeHttpRequests(a -> a.requestMatchers("/diag/**").permitAll().anyRequest().authenticated())
.httpBasic(Customizer.withDefaults())
.csrf(c -> c.disable())
.addFilterBefore(twiceFilter, BasicAuthenticationFilter.class);
return http.build();
}
}
@@ -0,0 +1,23 @@
package com.ankurm.filteraop.service;
import org.springframework.context.annotation.Lazy;
import org.springframework.stereotype.Service;
/** The self-invocation fix: call through an injected reference to the proxy instead of through this. */
@Service
public class FixedGreetingService {
private final FixedGreetingService self;
public FixedGreetingService(@Lazy FixedGreetingService self) {
this.self = self;
}
public String greet(String name) {
return "Hello, " + name;
}
public String greetTwice(String name) {
return self.greet(name) + " / " + self.greet(name);
}
}
@@ -0,0 +1,46 @@
package com.ankurm.filteraop.service;
import com.ankurm.filteraop.trace.Trace;
import org.springframework.stereotype.Service;
@Service
public class GreetingService {
private final Trace trace;
public GreetingService(Trace trace) {
this.trace = trace;
}
public String greet(String name) {
return "Hello, " + name;
}
/** Calls greet() twice through "this": the aspect sees greetTwice and never the two greet() calls. */
public String greetTwice(String name) {
return greet(name) + " / " + greet(name);
}
/** Calls a private method: the pointcut cannot match it, and a proxy cannot intercept it. */
public String callsPrivate(String name) {
return secret(name);
}
private String secret(String name) {
return "secret-" + name;
}
/** Uses an object made with new: no proxy, no advice, even though the signature matches the pointcut. */
public String usesHelper(String name) {
return new Helper().shout(name);
}
public String slow(long millis) throws InterruptedException {
Thread.sleep(millis);
return "slept " + millis;
}
public String fail() {
throw new IllegalStateException("service boom");
}
}
@@ -0,0 +1,8 @@
package com.ankurm.filteraop.service;
/** Lives in the service package, so the ServiceAspect pointcut matches it by signature, but it is not a Spring bean. */
public class Helper {
public String shout(String s) {
return s.toUpperCase() + "!";
}
}
@@ -0,0 +1,124 @@
package com.ankurm.filteraop.trace;
import jakarta.servlet.http.HttpServletRequest;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestAttributes;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import java.util.ArrayList;
import java.util.LinkedHashMap;
import java.util.List;
import java.util.Map;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.atomic.AtomicInteger;
/**
* The diagnostic at the heart of the demo: every Filter, HandlerInterceptor, aspect and advice
* writes one line here, in the order it really runs. Delete it (and every call to it) before
* shipping; it is a global, unbounded list.
*/
@Component
public class Trace {
private final List<String> lines = new CopyOnWriteArrayList<>();
private final Map<String, Long> nanos = new ConcurrentHashMap<>();
private final AtomicInteger seq = new AtomicInteger();
private volatile boolean showThread;
private final Map<String, String> threadLabels = new java.util.concurrent.ConcurrentHashMap<>();
public void clear() {
threadLabels.clear();
lines.clear();
nanos.clear();
seq.set(0);
}
public void showThread(boolean on) {
this.showThread = on;
}
/** Preferred: the caller passes the request, so the dispatcher type is exact. */
public void log(HttpServletRequest request, String who, String what) {
add(request == null ? "-" : request.getDispatcherType().name(), who, what);
}
/** For code that has no request in hand (aspects, advice): look it up from the current thread. */
public void log(String who, String what) {
RequestAttributes attrs = RequestContextHolder.getRequestAttributes();
String dispatch = attrs instanceof ServletRequestAttributes sra
? sra.getRequest().getDispatcherType().name() : "-";
add(dispatch, who, what);
}
private void add(String dispatch, String who, String what) {
String thread = showThread ? " <" + label(Thread.currentThread().getName()) + ">" : "";
lines.add(String.format("%02d %-8s %-30s %s%s", seq.incrementAndGet(), dispatch, who, what, thread));
}
/**
* Thread names carry ports and counters that change on every run. Container threads become
* tomcat-1, tomcat-2 in order of first appearance within one trace, Spring's MVC async executor
* threads become mvc-task-1, and anything else keeps its name.
*/
private String label(String name) {
return threadLabels.computeIfAbsent(name, n -> {
String kind = n.startsWith("http-nio") ? "tomcat" : n.startsWith("task-") ? "mvc-task" : null;
if (kind == null) {
return n;
}
long same = threadLabels.values().stream().filter(v -> v.startsWith(kind + "-")).count();
return kind + "-" + (same + 1);
});
}
public void record(String key, long elapsedNanos) {
nanos.put(key, elapsedNanos);
}
public long millis(String key) {
return nanos.getOrDefault(key, 0L) / 1_000_000;
}
public Map<String, Long> allMillis() {
Map<String, Long> out = new LinkedHashMap<>();
nanos.forEach((k, v) -> out.put(k, v / 1_000_000));
return out;
}
public List<String> lines() {
return new ArrayList<>(lines);
}
public String text() {
return String.join("\n", lines) + (lines.isEmpty() ? "" : "\n");
}
public int size() {
return lines.size();
}
/** Waits until no new line has appeared for quietMs: callbacks can run after the client has its response. */
public void settle(long quietMs, long maxMs) {
long deadline = System.currentTimeMillis() + maxMs;
int last = -1;
long lastChange = System.currentTimeMillis();
while (System.currentTimeMillis() < deadline) {
int now = seq.get();
if (now != last) {
last = now;
lastChange = System.currentTimeMillis();
} else if (System.currentTimeMillis() - lastChange >= quietMs) {
return;
}
try {
Thread.sleep(20);
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
return;
}
}
}
}
@@ -0,0 +1,31 @@
package com.ankurm.filteraop.web;
import com.ankurm.filteraop.trace.Trace;
import org.springframework.http.HttpStatus;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.ExceptionHandler;
import org.springframework.web.bind.annotation.RestControllerAdvice;
import java.util.Map;
@RestControllerAdvice
public class ApiExceptionHandler {
private final Trace trace;
public ApiExceptionHandler(Trace trace) {
this.trace = trace;
}
@ExceptionHandler(IllegalStateException.class)
ResponseEntity<Map<String, String>> handle(IllegalStateException e) {
trace.log("advice:@ExceptionHandler", "handling " + e.getClass().getSimpleName() + ": " + e.getMessage());
return ResponseEntity.status(HttpStatus.INTERNAL_SERVER_ERROR).body(Map.of("handled", e.getMessage()));
}
@ExceptionHandler(org.springframework.http.converter.HttpMessageNotReadableException.class)
ResponseEntity<Map<String, String>> unreadable(org.springframework.http.converter.HttpMessageNotReadableException e) {
trace.log("advice:@ExceptionHandler", "handling HttpMessageNotReadableException: " + e.getMessage());
return ResponseEntity.status(HttpStatus.BAD_REQUEST).body(Map.of("handled", "unreadable body"));
}
}
@@ -0,0 +1,50 @@
package com.ankurm.filteraop.web;
import org.apache.catalina.Container;
import org.apache.catalina.core.StandardContext;
import org.apache.tomcat.util.descriptor.web.FilterDef;
import org.apache.tomcat.util.descriptor.web.FilterMap;
import org.springframework.boot.tomcat.TomcatWebServer;
import org.springframework.boot.web.server.servlet.context.ServletWebServerApplicationContext;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
/**
* Diagnostic endpoint: the filter chain exactly as Tomcat will run it, in order, with the
* dispatcher types each filter is mapped to. Delete before shipping.
*/
@RestController
public class DiagController {
private final ServletWebServerApplicationContext context;
public DiagController(ServletWebServerApplicationContext context) {
this.context = context;
}
@GetMapping(value = "/diag/filters", produces = "text/plain")
public String filters() {
return String.join("\n", chain(context)) + "\n";
}
public static List<String> chain(ServletWebServerApplicationContext context) {
TomcatWebServer web = (TomcatWebServer) context.getWebServer();
List<String> out = new ArrayList<>();
for (Container host : web.getTomcat().getHost().findChildren()) {
StandardContext ctx = (StandardContext) host;
int n = 1;
for (FilterMap map : ctx.findFilterMaps()) {
FilterDef def = ctx.findFilterDef(map.getFilterName());
String[] dispatchers = map.getDispatcherNames();
out.add(String.format("%2d %-28s %-20s %s", n++, map.getFilterName(),
Arrays.toString(map.getURLPatterns()),
dispatchers.length == 0 ? "[REQUEST]" : Arrays.toString(dispatchers)));
}
}
return out;
}
}
@@ -0,0 +1,152 @@
package com.ankurm.filteraop.web;
import com.ankurm.filteraop.interceptor.RequiresRole;
import com.ankurm.filteraop.service.GreetingService;
import com.ankurm.filteraop.trace.Trace;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.context.request.async.DeferredResult;
import java.util.concurrent.Callable;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
@RestController
@RequestMapping("/api")
public class HelloController {
private final GreetingService service;
private final com.ankurm.filteraop.service.FixedGreetingService fixed;
private final Trace trace;
private final ScheduledExecutorService scheduler = Executors.newSingleThreadScheduledExecutor(r -> {
Thread t = new Thread(r, "demo-scheduler");
t.setDaemon(true);
return t;
});
public HelloController(GreetingService service, com.ankurm.filteraop.service.FixedGreetingService fixed, Trace trace) {
this.service = service;
this.fixed = fixed;
this.trace = trace;
}
@GetMapping("/hello/{name}")
public String hello(@PathVariable String name) {
trace.log("controller", "hello(" + name + ")");
return service.greet(name);
}
@GetMapping("/ping")
public String ping() {
trace.log("controller", "ping()");
return "pong";
}
@GetMapping("/twice/{name}")
public String twice(@PathVariable String name) {
return service.greetTwice(name);
}
@GetMapping("/twice-fixed/{name}")
public String twiceFixed(@PathVariable String name) {
return fixed.greetTwice(name);
}
@GetMapping("/private/{name}")
public String privateCall(@PathVariable String name) {
return service.callsPrivate(name);
}
@GetMapping("/helper/{name}")
public String helper(@PathVariable String name) {
return service.usesHelper(name);
}
@GetMapping("/boom")
public String boom() {
trace.log("controller", "boom() about to throw");
throw new IllegalStateException("controller boom");
}
@GetMapping("/service-boom")
public String serviceBoom() {
return service.fail();
}
@GetMapping("/unhandled")
public String unhandled() {
trace.log("controller", "unhandled() about to throw");
throw new UnsupportedOperationException("nobody handles this");
}
@PostMapping("/echo")
public String echo(@RequestBody String body) {
trace.log("controller", "echo received " + body.length() + " chars");
return "echo:" + body;
}
@GetMapping("/secure/data")
public String secure() {
trace.log("controller", "secure()");
return "secret data";
}
@GetMapping("/admin/report")
@RequiresRole("admin")
public String admin() {
trace.log("controller", "admin()");
return "admin report";
}
@GetMapping("/gated/hello")
public String gated() {
trace.log("controller", "gated()");
return "gated hello";
}
@GetMapping("/late/body")
public String late() {
trace.log("controller", "late() returning a String");
return "late body";
}
@GetMapping("/slow/{ms}")
public String slow(@PathVariable long ms) throws InterruptedException {
return service.slow(ms);
}
@GetMapping("/visibility/{id}")
public Item visibility(@PathVariable long id) {
trace.log("controller", "visibility(" + id + ")");
return new Item(id);
}
@GetMapping("/async-callable")
public Callable<String> asyncCallable() {
trace.log("controller", "asyncCallable() returns a Callable");
return () -> {
Thread.sleep(100);
trace.log("callable", "finished after 100 ms, returning");
return "callable-done";
};
}
@GetMapping("/async-deferred")
public DeferredResult<String> asyncDeferred() {
trace.log("controller", "asyncDeferred() returns a DeferredResult");
DeferredResult<String> result = new DeferredResult<>(5000L);
scheduler.schedule(() -> {
trace.log("deferred", "setResult");
result.setResult("deferred-done");
}, 100, TimeUnit.MILLISECONDS);
return result;
}
public record Item(long id) {
}
}
@@ -0,0 +1,25 @@
package com.ankurm.filteraop.web;
import com.ankurm.filteraop.trace.Trace;
import org.springframework.boot.webmvc.autoconfigure.WebMvcProperties;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.DispatcherServlet;
/**
* Replaces Boot's DispatcherServlet bean (it backs off for a bean named "dispatcherServlet") and
* applies the same four WebMvcProperties settings Boot's own configuration applies, verified with javap.
*/
@Configuration
public class ServletConfig {
@Bean(name = "dispatcherServlet")
DispatcherServlet dispatcherServlet(Trace trace, WebMvcProperties props) {
DispatcherServlet servlet = new TracingDispatcherServlet(trace);
servlet.setDispatchOptionsRequest(props.isDispatchOptionsRequest());
servlet.setDispatchTraceRequest(props.isDispatchTraceRequest());
servlet.setPublishEvents(props.isPublishRequestHandledEvents());
servlet.setEnableLoggingRequestDetails(props.isLogRequestDetails());
return servlet;
}
}
@@ -0,0 +1,30 @@
package com.ankurm.filteraop.web;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.web.servlet.DispatcherServlet;
/**
* DispatcherServlet with one line at the start and end of every doDispatch, so the trace shows
* where the servlet sits between the last filter and the first interceptor. doDispatch runs once
* per dispatch: REQUEST, then ERROR or ASYNC when there is one.
*/
public class TracingDispatcherServlet extends DispatcherServlet {
private final transient Trace trace;
public TracingDispatcherServlet(Trace trace) {
this.trace = trace;
}
@Override
protected void doDispatch(HttpServletRequest request, HttpServletResponse response) throws Exception {
trace.log(request, "servlet:DispatcherServlet", "doDispatch start");
try {
super.doDispatch(request, response);
} finally {
trace.log(request, "servlet:DispatcherServlet", "doDispatch end");
}
}
}
@@ -0,0 +1,3 @@
spring.autoconfigure.exclude=
spring.security.user.name=demo
spring.security.user.password=demo
@@ -0,0 +1,9 @@
spring.application.name=filter-interceptor-aop
server.error.include-message=always
# Spring Security is on the classpath only for the "security" scenario (SecurityOrderTest).
# Everywhere else its auto-configuration is excluded so it does not change the filter chain.
spring.autoconfigure.exclude=\
org.springframework.boot.security.autoconfigure.SecurityAutoConfiguration,\
org.springframework.boot.security.autoconfigure.UserDetailsServiceAutoConfiguration,\
org.springframework.boot.security.autoconfigure.web.servlet.SecurityFilterAutoConfiguration,\
org.springframework.boot.security.autoconfigure.web.servlet.ServletWebSecurityAutoConfiguration
@@ -0,0 +1 @@
static file served by ResourceHttpRequestHandler
@@ -0,0 +1,66 @@
package com.ankurm.filteraop;
import com.ankurm.filteraop.service.GreetingService;
import org.junit.jupiter.api.Test;
import org.springframework.aop.support.AopUtils;
import org.springframework.beans.factory.annotation.Autowired;
import static org.assertj.core.api.Assertions.assertThat;
class AopTrapsTest extends RealServerSupport {
@Autowired
GreetingService service;
private long count(String needle) {
return trace.lines().stream().filter(l -> l.contains(needle)).count();
}
private static long count(String log, String needle) {
return log.lines().filter(l -> l.contains(needle)).count();
}
@Test
void trapsThatAspectsDoNotSee() {
Transcript t = new Transcript("15-aop-traps.txt");
t.title("What the container injected for GreetingService");
t.line("class = " + service.getClass().getName().replaceAll("\\$\\$SpringCGLIB\\$\\$\\d+", "\\$\\$SpringCGLIB\\$\\$N"));
t.line("isAopProxy = " + AopUtils.isAopProxy(service));
t.line("isCglib = " + AopUtils.isCglibProxy(service));
for (String[] c : new String[][]{
{"/api/hello/ankur", "a normal call from the controller: the service aspect fires for greet"},
{"/api/twice/ankur", "self-invocation: greetTwice calls this.greet() twice"},
{"/api/twice-fixed/ankur", "the fix: FixedGreetingService calls greet() through an injected @Lazy reference to itself"},
{"/api/private/ankur", "callsPrivate calls a private method"},
{"/api/helper/ankur", "usesHelper calls new Helper().shout(...)"}}) {
trace.clear();
Resp r = get(c[0]);
String log = settled();
t.title("GET " + c[0] + " (" + c[1] + ")").line(r.brief());
if (c[0].equals("/api/twice/ankur")) {
assertThat(log).contains("GreetingService#greetTwice").doesNotContain("GreetingService#greet ");
}
if (c[0].equals("/api/twice-fixed/ankur")) {
assertThat(count(log, "before FixedGreetingService#greet ")).isEqualTo(2);
}
if (c[0].equals("/api/private/ankur") || c[0].equals("/api/helper/ankur")) {
assertThat(log).doesNotContain("#secret").doesNotContain("Helper#shout");
}
for (String line : log.split("\n")) {
if (line.contains("aspect:service") || line.contains("controller ")) {
t.line(line);
}
}
}
trace.clear();
service.greetTwice("direct");
t.title("Direct call on the proxy outside any web request: service.greetTwice(\"direct\")");
trace.lines().forEach(t::line);
assertThat(count("aspect:service")).isEqualTo(2);
assertThat(count("GreetingService#greet ")).isZero();
t.write();
System.out.println(t.text());
}
}
@@ -0,0 +1,83 @@
package com.ankurm.filteraop;
import com.ankurm.filteraop.trace.Trace;
import jakarta.servlet.Filter;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.webmvc.test.autoconfigure.AutoConfigureMockMvc;
import org.springframework.test.util.ReflectionTestUtils;
import org.springframework.test.web.servlet.MockMvc;
import org.springframework.test.web.servlet.MvcResult;
import static org.assertj.core.api.Assertions.assertThat;
import org.springframework.test.web.servlet.request.MockMvcRequestBuilders;
/** The same requests through MockMvc and through the real Tomcat, one trace each. */
@AutoConfigureMockMvc
class MockMvcVsServerTest extends RealServerSupport {
@Autowired
MockMvc mvc;
private static long count(String log, String needle) {
return log.lines().filter(l -> l.contains(needle)).count();
}
@Test
void sameRequestsTwoWays() throws Exception {
Transcript t = new Transcript("19-mockmvc-vs-server.txt");
Filter[] filters = (Filter[]) ReflectionTestUtils.getField(mvc, "filters");
t.title("Filters MockMvc will run (MockMvc.filters, outermost first)");
for (Filter f : filters) {
Object inner = ReflectionTestUtils.getField(f, "delegate");
t.line(" " + (inner == null ? f : inner).getClass().getSimpleName());
}
for (String path : new String[]{"/api/hello/ankur", "/nope"}) {
trace.clear();
int mockStatus = mvc.perform(MockMvcRequestBuilders.get(path)).andReturn().getResponse().getStatus();
String mock = settled();
trace.clear();
Resp real = this.get(path);
String server = settled();
t.title("GET " + path + " MockMvc: HTTP " + mockStatus + ", " + mock.lines().count() + " trace lines");
t.block(mock);
t.title("GET " + path + " real Tomcat: HTTP " + real.status() + ", " + server.lines().count() + " trace lines");
t.block(server);
}
trace.clear();
Throwable thrown = null;
try {
mvc.perform(MockMvcRequestBuilders.get("/api/unhandled"));
} catch (Exception e) {
thrown = e;
}
String mock = settled();
t.title("GET /api/unhandled MockMvc: perform() THREW " + (thrown == null ? "nothing" : thrown.getClass().getSimpleName()
+ " (cause " + thrown.getCause().getClass().getSimpleName() + ")"));
t.block(mock);
trace.clear();
MvcResult started = mvc.perform(MockMvcRequestBuilders.get("/api/async-callable")).andReturn();
String before = settled();
t.title("GET /api/async-callable MockMvc, after perform() and before asyncDispatch: asyncStarted="
+ started.getRequest().isAsyncStarted());
t.block(before);
trace.clear();
mvc.perform(MockMvcRequestBuilders.asyncDispatch(started));
String after = settled();
t.title("... then mvc.perform(MockMvcRequestBuilders.asyncDispatch(result))");
t.block(after);
t.write();
System.out.println(t.text());
assertThat(thrown).isInstanceOf(jakarta.servlet.ServletException.class);
assertThat(count(mock, "ERROR")).isZero();
assertThat(count(before, "afterConcurrentHandlingStarted")).isEqualTo(2);
assertThat(count(after, "ASYNC interceptor:A preHandle")).isEqualTo(1);
}
}
@@ -0,0 +1,29 @@
package com.ankurm.filteraop;
import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;
import static org.assertj.core.api.Assertions.assertThat;
/** An interceptor that casts the handler to HandlerMethod without checking. */
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT,
properties = "demo.naive-interceptor=true")
class NaiveCastTest extends RealServerSupport {
@Test
void castFailsOnStaticResources() {
Transcript t = new Transcript("13-handler-cast.txt");
Resp api = get("/api/hello/ankur");
t.title("GET /api/hello/ankur with the naive (HandlerMethod) cast").line(api.brief());
Resp file = get("/hello.txt");
t.title("GET /hello.txt with the naive cast").line(file.brief());
t.title("Trace of the GET /hello.txt request (the last one run)");
trace.clear();
Resp again = get("/hello.txt");
t.block(settled());
t.write();
System.out.println(t.text());
assertThat(api.status()).isEqualTo(200);
assertThat(file.status()).isEqualTo(500);
}
}
@@ -0,0 +1,26 @@
package com.ankurm.filteraop;
import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;
import static org.assertj.core.api.Assertions.assertThat;
/** spring.web.resources.add-mappings=false removes the /** resource handler, so a 404 has no handler at all. */
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT,
properties = "spring.web.resources.add-mappings=false")
class NoHandlerTest extends RealServerSupport {
@Test
void notFoundWithoutAnyHandler() {
Transcript t = new Transcript("12-no-handler.txt");
Resp r = get("/nope");
t.title("spring.web.resources.add-mappings=false, GET /nope").line(r.brief()).block(settled());
trace.clear();
Resp s = get("/hello.txt");
t.title("same setting, GET /hello.txt (the file exists but nothing serves it)").line(s.brief()).block(settled());
t.write();
System.out.println(t.text());
assertThat(r.status()).isEqualTo(404);
assertThat(s.status()).isEqualTo(404);
}
}
@@ -0,0 +1,288 @@
package com.ankurm.filteraop;
import com.ankurm.filteraop.web.DiagController;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.web.server.servlet.context.ServletWebServerApplicationContext;
import java.util.List;
import static org.assertj.core.api.Assertions.assertThat;
/**
* One real Tomcat, one request per scenario. Each test writes output/NN-*.txt and asserts the
* facts the article quotes from it, so the transcripts cannot drift from the code.
*/
class OrderAndDispatchTest extends RealServerSupport {
@Autowired
ServletWebServerApplicationContext ctx;
/** The fragments must all appear in the log, in this order. */
private static void inOrder(String log, String... fragments) {
int from = 0;
for (String f : fragments) {
int at = log.indexOf(f, from);
assertThat(at).as("'%s' after offset %d in:%n%s", f, from, log).isGreaterThanOrEqualTo(0);
from = at + f.length();
}
}
private static long count(String log, String needle) {
return log.lines().filter(l -> l.contains(needle)).count();
}
private Resp scenario(Transcript t, String title, String path, String... headers) {
trace.clear();
Resp r = title.startsWith("POST ") ? post(path, "x", headers) : get(path, headers);
t.title(title).line(r.brief());
return r;
}
private String logOf(Transcript t) {
String log = settled();
t.block(log);
return log;
}
@Test
void filterChainAsTomcatRunsIt() {
List<String> chain = DiagController.chain(ctx);
Transcript t = new Transcript("02-filter-chain-order.txt");
t.title("Tomcat's real filter chain (StandardContext.findFilterMaps), outermost first");
t.line("## filter name url patterns dispatcher types");
chain.forEach(t::line);
t.title("The same list from GET /diag/filters over HTTP");
Resp r = get("/diag/filters");
t.cmd("curl localhost:PORT/diag/filters").block(r.body());
t.write();
String all = String.join("\n", chain);
inOrder(all, "characterEncodingFilter", "formContentFilter", "requestContextFilter", "rawFilter", "accessLog",
"apiKeyFilter", "visibilityFilter", "bodyFilter", "faultFilter");
assertThat(chain.stream().filter(l -> l.contains("rawFilter")).findFirst().orElseThrow()).endsWith("[REQUEST]");
assertThat(chain.stream().filter(l -> l.contains("accessLog")).findFirst().orElseThrow())
.contains("ERROR").contains("ASYNC");
assertThat(r.body().strip()).isEqualTo(String.join("\n", chain).strip());
}
@Test
void happyPath() {
Transcript t = new Transcript("03-happy-path.txt");
Resp r = scenario(t, "GET /api/hello/ankur on a real Tomcat", "/api/hello/ankur");
String log = logOf(t);
t.write();
assertThat(r.body()).isEqualTo("Hello, ankur");
inOrder(log, "filter:raw(order 5) before chain", "filter:accessLog(order 10) before chain",
"doDispatch start", "interceptor:A preHandle", "interceptor:B preHandle",
"aspect:controller before", "controller hello(ankur)",
"aspect:service before", "aspect:service after",
"aspect:controller after", "interceptor:B postHandle",
"interceptor:A postHandle", "interceptor:B afterCompletion",
"interceptor:A afterCompletion", "doDispatch end",
"filter:accessLog(order 10) after chain", "filter:raw(order 5) after chain");
}
@Test
void exceptions() {
Transcript t = new Transcript("04-exceptions.txt");
Resp a = scenario(t, "GET /api/boom: controller throws, @RestControllerAdvice handles it", "/api/boom");
String boom = logOf(t);
assertThat(a.status()).isEqualTo(500);
assertThat(boom).doesNotContain("postHandle");
inOrder(boom, "aspect:controller after HelloController#boom THREW", "advice:@ExceptionHandler",
"interceptor:B afterCompletion ex=null", "interceptor:A afterCompletion ex=null");
Resp b = scenario(t, "GET /api/service-boom: the service throws, the controller never catches", "/api/service-boom");
String sboom = logOf(t);
inOrder(sboom, "aspect:service after GreetingService#fail THREW",
"aspect:controller after HelloController#serviceBoom THREW", "advice:@ExceptionHandler");
Resp c = scenario(t, "GET /api/unhandled: nobody handles it, Boot's /error takes over", "/api/unhandled");
String unhandled = logOf(t);
assertThat(unhandled).contains("afterCompletion ex=UnsupportedOperationException");
assertThat(unhandled).contains("filter:accessLog(order 10) after chain status=200");
assertThat(c.status()).isEqualTo(500);
String errorPart = unhandled.substring(unhandled.indexOf(" ERROR "));
assertThat(errorPart).doesNotContain("filter:");
Resp d = scenario(t, "GET /api/hello/x with X-Filter-Throw: the FILTER throws", "/api/hello/x", "X-Filter-Throw", "1");
String filterThrows = logOf(t);
assertThat(filterThrows).doesNotContain("advice:");
assertThat(filterThrows).doesNotContain("REQUEST servlet:DispatcherServlet");
assertThat(filterThrows).contains("ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error");
assertThat(d.status()).isEqualTo(500);
t.write();
}
@Test
void staticResourcesAnd404() {
Transcript t = new Transcript("05-static-404-error-dispatch.txt");
scenario(t, "GET /hello.txt: a static resource", "/hello.txt");
String file = logOf(t);
assertThat(file).contains("preHandle handler=ResourceHttpRequestHandler");
assertThat(file).doesNotContain("aspect:");
Resp nope = scenario(t, "GET /nope: no controller, no file", "/nope");
String missing = logOf(t);
assertThat(nope.status()).isEqualTo(404);
inOrder(missing, "REQUEST interceptor:A preHandle handler=ResourceHttpRequestHandler",
"REQUEST interceptor:A afterCompletion ex=null",
"ERROR servlet:DispatcherServlet doDispatch start",
"ERROR interceptor:A preHandle handler=HandlerMethod BasicErrorController#error");
assertThat(missing.substring(0, missing.indexOf(" ERROR "))).doesNotContain("postHandle");
Resp wrongMethod = scenario(t, "POST /api/ping: the path exists, the method does not", "/api/ping");
String wrong = logOf(t);
assertThat(wrongMethod.status()).isEqualTo(405);
t.write();
}
@Test
void shortCircuits() {
Transcript t = new Transcript("06-short-circuits.txt");
Resp rejected = scenario(t, "GET /api/secure/data without a key: the FILTER answers", "/api/secure/data");
String filterReject = logOf(t);
assertThat(rejected.status()).isEqualTo(401);
assertThat(filterReject).doesNotContain("DispatcherServlet").doesNotContain("interceptor").doesNotContain("aspect");
assertThat(filterReject).contains("filter:accessLog(order 10) after chain status=401");
scenario(t, "GET /api/secure/data with the key", "/api/secure/data", "X-Api-Key", "demo-key");
assertThat(logOf(t)).contains("controller secure()");
Resp denied = scenario(t, "GET /api/admin/report as a plain user: the INTERCEPTOR denies", "/api/admin/report", "X-Role", "user");
String roleDenied = logOf(t);
assertThat(denied.status()).isEqualTo(403);
assertThat(roleDenied).contains("deny 403").doesNotContain("aspect:").doesNotContain("controller ");
assertThat(roleDenied).contains("filter:accessLog(order 10) after chain status=403");
scenario(t, "GET /api/admin/report as admin", "/api/admin/report", "X-Role", "admin");
assertThat(logOf(t)).contains("allow").contains("admin()");
scenario(t, "GET /api/gated/hello: gate returns true", "/api/gated/hello");
assertThat(logOf(t)).contains("interceptor:gate preHandle -> true");
Resp write = scenario(t, "GET /api/gated/hello?mode=write: gate returns false after writing a 403 body", "/api/gated/hello?mode=write");
String gateWrite = logOf(t);
assertThat(write.status()).isEqualTo(403);
assertThat(write.body()).contains("gate closed");
assertThat(gateWrite).contains("interceptor:A afterCompletion").doesNotContain("interceptor:B")
.doesNotContain("postHandle").doesNotContain("aspect:");
Resp silent = scenario(t, "GET /api/gated/hello?mode=silent: gate returns false and writes nothing", "/api/gated/hello?mode=silent");
logOf(t);
assertThat(silent.status()).isEqualTo(200);
assertThat(silent.body()).isEmpty();
t.write();
}
@Test
void async() {
trace.showThread(true);
Transcript t = new Transcript("07-async.txt");
for (String path : new String[]{"/api/async-callable", "/api/async-deferred"}) {
Resp r = scenario(t, "GET " + path + (path.contains("callable") ? ": returns a Callable" : ": returns a DeferredResult completed by another thread"), path);
String log = logOf(t);
assertThat(r.body()).endsWith("-done");
assertThat(count(log, "interceptor:A preHandle")).isEqualTo(2);
assertThat(count(log, "afterConcurrentHandlingStarted")).isEqualTo(2);
assertThat(count(log, "interceptor:A postHandle")).isEqualTo(1);
assertThat(count(log, "interceptor:A afterCompletion")).isEqualTo(1);
assertThat(count(log, "REQUEST filter:accessLog(order 10) before")).isEqualTo(1);
assertThat(log).contains("after chain status=200 asyncStarted=true");
assertThat(log.substring(log.indexOf(" ASYNC "))).doesNotContain("filter:").doesNotContain("aspect:");
}
t.write();
}
@Test
void requestBody() {
Transcript t = new Transcript("08-request-body.txt");
for (String mode : new String[]{"none", "consume", "cache", "consume-wrapped", "replay"}) {
trace.clear();
Resp r = "none".equals(mode) ? post("/api/echo", "hello body") : post("/api/echo", "hello body", "X-Body-Mode", mode);
t.title("POST /api/echo \"hello body\" X-Body-Mode=" + mode).line(r.brief());
String log = logOf(t);
switch (mode) {
case "none", "cache", "replay" -> {
assertThat(r.status()).isEqualTo(200);
assertThat(r.body()).isEqualTo("echo:hello body");
}
case "consume", "consume-wrapped" -> {
assertThat(r.status()).isEqualTo(400);
assertThat(log).contains("handling HttpMessageNotReadableException: Required request body is missing");
assertThat(log).doesNotContain("aspect:controller");
}
default -> throw new IllegalStateException(mode);
}
if (mode.equals("cache")) {
assertThat(log).contains("before chain: getContentAsByteArray().length=0")
.contains("after chain: getContentAsByteArray().length=10");
}
}
for (String mode : new String[]{"copy", "forget"}) {
trace.clear();
Resp r = get("/api/hello/ankur", "X-Resp-Mode", mode);
t.title("GET /api/hello/ankur X-Resp-Mode=" + mode + " (ContentCachingResponseWrapper)")
.line(r.brief() + " Content-Length=" + r.headers().getContentLength());
String log = logOf(t);
assertThat(log).contains("response wrapper holds 12 bytes");
if (mode.equals("copy")) {
assertThat(r.body()).isEqualTo("Hello, ankur");
} else {
assertThat(r.body()).isEmpty();
assertThat(r.status()).isEqualTo(200);
}
}
t.write();
}
@Test
void visibility() {
Transcript t = new Transcript("09-visibility.txt");
scenario(t, "GET /api/visibility/42: what each layer can see", "/api/visibility/42", "X-Probe", "hello");
String log = logOf(t);
t.write();
String flat = log.replaceAll("[ ]+", " ");
assertThat(flat).contains("filter:visibility(order 25) before chain: method=GET uri=/api/visibility/42 X-Probe=hello handler attribute=null");
assertThat(flat).contains("after chain: handler attribute=HandlerMethod visibility pattern=/api/visibility/{id} status=200");
assertThat(flat).contains("pathVars(raw strings)={id=42}");
assertThat(flat).contains("aspect:visibility before arg[0]=42 (Long");
assertThat(flat).contains("after returned=Item[id=42] (Item)");
}
@Test
void timing() {
Transcript t = new Transcript("10-timing.txt");
scenario(t, "GET /api/slow/80 (the service sleeps 80 ms)", "/api/slow/80");
logOf(t);
t.title("Elapsed time seen by each layer, milliseconds (indicative: timing varies run to run)");
long filter = trace.millis("filter:accessLog(order 10)");
long interceptor = trace.millis("interceptor:timing");
long controller = trace.millis("aspect:controller");
long service = trace.millis("aspect:service");
t.line(String.format("%-28s %4d ms", "filter (accessLog)", filter));
t.line(String.format("%-28s %4d ms", "interceptor (timing)", interceptor));
t.line(String.format("%-28s %4d ms", "aspect around controller", controller));
t.line(String.format("%-28s %4d ms", "aspect around service", service));
t.write();
assertThat(service).isGreaterThanOrEqualTo(80);
assertThat(controller).isGreaterThanOrEqualTo(service);
assertThat(interceptor).isGreaterThanOrEqualTo(controller);
assertThat(filter).isGreaterThanOrEqualTo(interceptor);
}
@Test
void lateHeader() {
Transcript t = new Transcript("11-late-header.txt");
Resp r = scenario(t, "GET /api/late/body: header set in preHandle and in postHandle", "/api/late/body");
String log = logOf(t);
t.line("X-Added-In-PreHandle = " + r.headers().getFirst("X-Added-In-PreHandle"));
t.line("X-Added-In-PostHandle = " + r.headers().getFirst("X-Added-In-PostHandle"));
t.write();
assertThat(log).contains("postHandle response.isCommitted()=true");
assertThat(r.headers().getFirst("X-Added-In-PreHandle")).isEqualTo("yes");
assertThat(r.headers().getFirst("X-Added-In-PostHandle")).isNull();
}
}
@@ -0,0 +1,55 @@
package com.ankurm.filteraop;
import com.ankurm.filteraop.interceptor.PatternProbeConfig;
import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;
import java.util.ArrayList;
import java.util.List;
import static org.assertj.core.api.Assertions.assertThat;
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT,
properties = "demo.pattern-probe=true")
class PathPatternTest extends RealServerSupport {
@Test
void whichPatternsMatchWhichUrls() {
Transcript t = new Transcript("14-path-patterns.txt");
t.title("Interceptors registered with addPathPatterns(...), one per pattern");
for (String p : PatternProbeConfig.PATTERNS) {
t.line(" " + p);
}
t.title("Which patterns fired (REQUEST dispatch) for each URL, and the HTTP status");
String[] urls = {
"/api/hello/ankur", "/api/hello/ankur/", "/api/hello", "/api/hello/", "/api/ping", "/api/ping/",
"/API/hello/ankur", "/api/hello/a/b", "/api/hello/ankur.json", "/api/hello/ankur;x=1", "/nope"
};
for (String url : urls) {
trace.clear();
Resp r = get(url);
trace.settle(200, 3000);
List<String> request = new ArrayList<>();
List<String> error = new ArrayList<>();
for (String line : trace.lines()) {
if (line.contains(" probe ")) {
String[] parts = line.trim().split("\\s+");
(parts[1].equals("ERROR") ? error : request).add(parts[parts.length - 1]);
}
}
switch (url) {
case "/api/hello/ankur" -> {
assertThat(r.status()).isEqualTo(200);
assertThat(request).containsExactly("/api/**", "/api/hello/*", "/api/hello/**", "/api/hello/{name}", "/**");
}
case "/api/hello/ankur/", "/api/ping/", "/API/hello/ankur" -> assertThat(r.status()).isEqualTo(404);
case "/api/hello" -> assertThat(request).contains("/api/hello", "/api/hello/**").doesNotContain("/api/hello/*");
default -> {
}
}
t.line(String.format("%-24s %3d %-62s ERROR dispatch: %s", url, r.status(), request, error));
}
t.write();
System.out.println(t.text());
}
}
@@ -0,0 +1,64 @@
package com.ankurm.filteraop;
import com.ankurm.filteraop.trace.Trace;
import org.junit.jupiter.api.BeforeEach;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.boot.test.web.server.LocalServerPort;
import org.springframework.http.HttpHeaders;
import org.springframework.web.client.RestClient;
import java.nio.charset.StandardCharsets;
/** A real embedded Tomcat on a random port, called with RestClient (JDK HttpClient underneath). */
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
abstract class RealServerSupport {
@LocalServerPort
int port;
@Autowired
Trace trace;
RestClient client;
record Resp(int status, HttpHeaders headers, String body) {
String brief() {
String b = body.strip().replaceAll("\"timestamp\":\"[^\"]*\"", "\"timestamp\":\"...\"");
return "HTTP " + status + (b.isEmpty() ? " (empty body)" : " body=" + b);
}
}
@BeforeEach
void init() {
client = RestClient.create("http://localhost:" + port);
trace.showThread(false);
trace.clear();
}
Resp get(String path, String... headers) {
return send("GET", path, null, headers);
}
Resp post(String path, String body, String... headers) {
return send("POST", path, body, headers);
}
private Resp send(String method, String path, String body, String... headers) {
RestClient.RequestBodySpec spec = client.method(org.springframework.http.HttpMethod.valueOf(method)).uri(path);
for (int i = 0; i < headers.length; i += 2) {
spec = spec.header(headers[i], headers[i + 1]);
}
if (body != null) {
spec = spec.contentType(org.springframework.http.MediaType.TEXT_PLAIN).body(body);
}
return spec.exchange((req, res) -> new Resp(res.getStatusCode().value(), res.getHeaders(),
new String(res.getBody().readAllBytes(), StandardCharsets.UTF_8)));
}
/** Callbacks can run after the client already has its answer; wait for the trace to go quiet. */
String settled() {
trace.settle(300, 5000);
return trace.text();
}
}
@@ -0,0 +1,27 @@
package com.ankurm.filteraop;
import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.ActiveProfiles;
import static org.assertj.core.api.Assertions.assertThat;
/** Same app with a FilterRegistrationBean(enabled=false) for the filter: it now runs once. */
@ActiveProfiles("security")
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT, properties = "demo.twice.fix=true")
class SecurityDoubleFixTest extends RealServerSupport {
@Test
void runsOnceWithTheFix() {
Transcript t = new Transcript("18-security-double-registration-fixed.txt");
Resp r = get("/api/hello/ankur", "Authorization", "Basic " + java.util.Base64.getEncoder().encodeToString("demo:demo".getBytes()));
t.title("Same request with FilterRegistrationBean(enabled=false): GET /api/hello/ankur").line(r.brief());
String log = settled();
t.block(log);
long runs = log.lines().filter(l -> l.contains("filter:twice")).count();
t.line("filter:twice ran " + runs + " time(s) for ONE request");
t.write();
System.out.println(t.text());
assertThat(runs).isEqualTo(1);
}
}
@@ -0,0 +1,27 @@
package com.ankurm.filteraop;
import org.junit.jupiter.api.Test;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.ActiveProfiles;
import static org.assertj.core.api.Assertions.assertThat;
/** The same filter bean is registered with Tomcat AND added to the Security chain; a plain Filter then runs twice. */
@ActiveProfiles("security")
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT, properties = "demo.twice.fix=false")
class SecurityDoubleRunTest extends RealServerSupport {
@Test
void runsTwiceWithoutTheFix() {
Transcript t = new Transcript("17-security-double-registration.txt");
Resp r = get("/api/hello/ankur", "Authorization", "Basic " + java.util.Base64.getEncoder().encodeToString("demo:demo".getBytes()));
t.title("A plain Filter bean that is also in the SecurityFilterChain: GET /api/hello/ankur").line(r.brief());
String log = settled();
t.block(log);
long runs = log.lines().filter(l -> l.contains("filter:twice")).count();
t.line("filter:twice ran " + runs + " times for ONE request");
t.write();
System.out.println(t.text());
assertThat(runs).isEqualTo(2);
}
}
@@ -0,0 +1,59 @@
package com.ankurm.filteraop;
import com.ankurm.filteraop.web.DiagController;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.beans.factory.annotation.Qualifier;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.boot.web.server.servlet.context.ServletWebServerApplicationContext;
import org.springframework.security.web.FilterChainProxy;
import org.springframework.test.context.ActiveProfiles;
import jakarta.servlet.Filter;
import static org.assertj.core.api.Assertions.assertThat;
/** Spring Security 7.1.2 on the classpath, "security" profile on: where its filter chain sits among the servlet filters. */
@ActiveProfiles("security")
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
class SecurityOrderTest extends RealServerSupport {
@Autowired
ServletWebServerApplicationContext ctx;
@Autowired
@Qualifier("springSecurityFilterChain")
Filter springSecurityFilterChain;
private Resp getAs(String path, String user, String pass) {
String basic = java.util.Base64.getEncoder().encodeToString((user + ":" + pass).getBytes());
return get(path, "Authorization", "Basic " + basic);
}
@Test
void securityChainSitsInTheServletChain() {
Transcript t = new Transcript("16-security-order.txt");
t.title("Tomcat's filter chain with Spring Security 7.1.2 enabled");
DiagController.chain(ctx).forEach(t::line);
FilterChainProxy proxy = (FilterChainProxy) springSecurityFilterChain;
t.title("Inside springSecurityFilterChain (FilterChainProxy.getFilterChains().get(0).getFilters()), in order");
int i = 1;
for (Filter f : proxy.getFilterChains().get(0).getFilters()) {
t.line(String.format("%2d %s", i++, f.getClass().getSimpleName()));
}
trace.clear();
Resp noAuth = get("/api/hello/ankur");
t.title("GET /api/hello/ankur with no credentials").line(noAuth.brief()).block(settled());
trace.clear();
Resp ok = getAs("/api/hello/ankur", "demo", "demo");
t.title("GET /api/hello/ankur as demo:demo").line(ok.brief()).block(settled());
assertThat(noAuth.status()).isEqualTo(401);
assertThat(ok.status()).isEqualTo(200);
t.write();
System.out.println(t.text());
}
}
@@ -0,0 +1,56 @@
package com.ankurm.filteraop;
import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.Paths;
/** Writes output/NN-name.txt; the tests assert the same facts, so the transcripts cannot drift from the code. */
final class Transcript {
private final StringBuilder sb = new StringBuilder();
private final String fileName;
Transcript(String fileName) {
this.fileName = fileName;
}
Transcript title(String text) {
if (sb.length() > 0) {
sb.append('\n');
}
sb.append("### ").append(text).append('\n');
return this;
}
Transcript cmd(String text) {
sb.append("$ ").append(text).append('\n');
return this;
}
Transcript line(String text) {
sb.append(text).append('\n');
return this;
}
Transcript block(String text) {
sb.append(text);
if (!text.endsWith("\n")) {
sb.append('\n');
}
return this;
}
String text() {
return sb.toString();
}
void write() {
try {
Path out = Paths.get("output", fileName);
Files.createDirectories(out.getParent());
Files.writeString(out, sb.toString());
} catch (IOException e) {
throw new RuntimeException(e);
}
}
}
@@ -0,0 +1,141 @@
package com.ankurm.filteraop;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.junit.jupiter.api.Test;
import org.springframework.boot.SpringBootVersion;
import org.springframework.core.SpringVersion;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.servlet.config.annotation.InterceptorRegistration;
import org.springframework.web.servlet.config.annotation.PathMatchConfigurer;
import org.springframework.web.util.pattern.PathPatternParser;
import java.io.IOException;
import java.lang.reflect.Method;
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.Arrays;
import java.util.TreeSet;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
import static org.assertj.core.api.Assertions.assertThat;
/** Facts read from the jars on the classpath, not from documentation. */
class VersionsAndJarsTest {
private static String jar(Class<?> c) {
String loc = c.getProtectionDomain().getCodeSource().getLocation().getPath();
return loc.substring(loc.lastIndexOf('/') + 1);
}
private static String starterDeps(String artifact, String version) throws IOException {
Path pom = Path.of(System.getProperty("user.home"), ".m2/repository/org/springframework/boot", artifact, version,
artifact + "-" + version + ".pom");
Matcher m = Pattern.compile("<artifactId>([^<]+)</artifactId>").matcher(Files.readString(pom));
TreeSet<String> out = new TreeSet<>();
boolean first = true;
while (m.find()) {
if (first) {
first = false;
continue;
}
out.add(m.group(1));
}
out.remove("spring-boot-starter-parent");
return out.toString();
}
private static boolean hasMethod(Class<?> c, String name) {
return Arrays.stream(c.getMethods()).anyMatch(m -> m.getName().equals(name));
}
static class Probe extends OncePerRequestFilter {
boolean errorDispatchSkipped() {
return shouldNotFilterErrorDispatch();
}
boolean asyncDispatchSkipped() {
return shouldNotFilterAsyncDispatch();
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
throws ServletException, IOException {
chain.doFilter(request, response);
}
}
@Test
void versionsAndJarFacts() throws Exception {
Transcript t = new Transcript("01-versions-and-jars.txt");
t.title("Versions on the classpath");
t.line("JDK " + Runtime.version());
t.line("Spring Boot " + SpringBootVersion.getVersion());
t.line("Spring Framework " + SpringVersion.getVersion());
t.line("Spring Security " + org.springframework.security.core.SpringSecurityCoreVersion.getVersion());
t.line("Tomcat " + org.apache.catalina.util.ServerInfo.getServerNumber());
t.line("AspectJ weaver " + jar(org.aspectj.lang.JoinPoint.class));
t.title("The Boot 4 AOP starter, read from its published pom in ~/.m2");
t.line("spring-boot-starter-aspectj 4.1.2 depends on " + starterDeps("spring-boot-starter-aspectj", "4.1.2"));
t.line("spring-boot-starter-aop: no 4.x release exists on Maven Central (see 20-central-versions.txt)");
t.title("Which jar each piece lives in");
for (String name : new String[]{
"org.springframework.boot.autoconfigure.aop.AopAutoConfiguration",
"org.springframework.boot.web.servlet.FilterRegistrationBean",
"org.springframework.boot.servlet.filter.OrderedFilter",
"org.springframework.boot.tomcat.TomcatWebServer",
"org.springframework.boot.webmvc.autoconfigure.DispatcherServletAutoConfiguration",
"org.springframework.web.servlet.handler.MappedInterceptor",
"org.springframework.web.filter.OncePerRequestFilter",
"org.springframework.web.servlet.AsyncHandlerInterceptor",
"org.springframework.boot.security.autoconfigure.web.servlet.SecurityFilterAutoConfiguration"}) {
t.line(String.format("%-98s %s", name, jar(Class.forName(name))));
}
t.title("Orders of the filters Boot registers (constants read from the jars)");
t.line("OrderedCharacterEncodingFilter.getOrder() = " + new org.springframework.boot.servlet.filter.OrderedCharacterEncodingFilter().getOrder());
t.line("OrderedFormContentFilter.DEFAULT_ORDER = " + org.springframework.boot.servlet.filter.OrderedFormContentFilter.DEFAULT_ORDER);
t.line("OrderedRequestContextFilter.getOrder() = " + new org.springframework.boot.servlet.filter.OrderedRequestContextFilter().getOrder());
t.line("SecurityFilterProperties.DEFAULT_FILTER_ORDER = " + org.springframework.boot.security.autoconfigure.web.servlet.SecurityFilterProperties.DEFAULT_FILTER_ORDER);
t.line("Ordered.LOWEST_PRECEDENCE (no @Order) = " + org.springframework.core.Ordered.LOWEST_PRECEDENCE);
t.title("OncePerRequestFilter defaults (a subclass asked at runtime)");
Probe p = new Probe();
t.line("shouldNotFilterErrorDispatch() = " + p.errorDispatchSkipped());
t.line("shouldNotFilterAsyncDispatch() = " + p.asyncDispatchSkipped());
t.title("InterceptorRegistration public methods (Framework 7.0.10)");
t.line(Arrays.stream(InterceptorRegistration.class.getMethods())
.filter(m -> m.getDeclaringClass() == InterceptorRegistration.class)
.map(m -> m.getName() + (m.isAnnotationPresent(Deprecated.class) ? " [deprecated]" : ""))
.sorted().distinct().toList().toString());
t.title("PathMatchConfigurer public setters and their @Deprecated flag");
for (Method m : PathMatchConfigurer.class.getMethods()) {
if (m.getDeclaringClass() == PathMatchConfigurer.class && m.getName().startsWith("set")) {
Deprecated d = m.getAnnotation(Deprecated.class);
t.line(String.format("%-34s %s", m.getName(), d == null ? "-" : "@Deprecated(since=\"" + d.since() + "\", forRemoval=" + d.forRemoval() + ")"));
}
}
t.title("PathPatternParser: public setters, and whether the trailing-slash switches still exist");
PathPatternParser parser = new PathPatternParser();
t.line("setters = " + Arrays.stream(PathPatternParser.class.getMethods())
.filter(m -> m.getDeclaringClass() == PathPatternParser.class && m.getName().startsWith("set"))
.map(Method::getName).sorted().toList());
t.line("caseSensitive = " + parser.isCaseSensitive());
t.line("has setMatchOptionalTrailingSeparator = " + hasMethod(PathPatternParser.class, "setMatchOptionalTrailingSeparator"));
t.line("has PathMatchConfigurer.setUseTrailingSlashMatch = " + hasMethod(PathMatchConfigurer.class, "setUseTrailingSlashMatch"));
t.write();
System.out.println(t.text());
assertThat(SpringBootVersion.getVersion()).isEqualTo("4.1.2");
assertThat(org.springframework.boot.security.autoconfigure.web.servlet.SecurityFilterProperties.DEFAULT_FILTER_ORDER).isEqualTo(-100);
assertThat(p.errorDispatchSkipped()).isTrue();
assertThat(p.asyncDispatchSkipped()).isTrue();
}
}