[spring-projects/spring-boot]微调和审查日志记录输出

3

/抄送@rstoyanchev

philwebb

0

此外，我们应该跟踪SPR-16954的结果。

bclozel

2

一些具体的事项：

、、org.springframework.core.codec下的日志记录现在明确设计为在调试级别紧凑，并且不需要更改单个包设置。开箱即用地启用它应该是可能的，并且很有帮助。如果情况并非如此，例如，如果我们错过或重新引入了将来导致 DEBUG 产生大量输出的任何内容，我们可以将其视为框架问题。org.springframework.httporg.springframework.webdevtools
DispatcherServlet有一个enableLoggingRequestDetails可以与开发工具一起使用的新属性。在 WebFlux 中，相同的属性位于CodecConfigurer#defaultCodecs which applies to both server side (WebFluxConfigurer ) and client side (WebClient.Builder`）下。
DefaultErrorWebExceptionHandler可以使其打印状态代码的日志消息更加简洁。HttpWebHandlerAdapter记录详细的响应信息，包括状态。
现在ServerWebExchange有了这个getLogPrefix()方法，它可以用来在 Spring Boot 中添加任何可以访问ServerWebExchange.否则的话是这样的：

[reactor-http-server-epoll-6] 54:52 o.s.w.s.a.HttpWebHandlerAdapter: [83b08de0] HTTP GET "/carsss", headers={masked}
[reactor-http-server-epoll-6] 54:52 o.s.w.r.h.SimpleUrlHandlerMapping: [83b08de0] Mapped to ResourceWebHandler ["classpath:/META-INF/resources/", "classpath:/resources/", "classpath:/static/", "classpath:/public/"]
[reactor-http-server-epoll-6] 54:52 o.s.w.r.r.ResourceWebHandler: [83b08de0] Resource not found
[reactor-http-server-epoll-6] 54:52 o.s.w.r.f.s.RouterFunctions: [83b08de0] Matched org.springframework.web.reactive.function.server.RequestPredicates$$Lambda$659/369798142@1b4d833b
[reactor-http-server-epoll-6] 54:52 o.s.b.a.w.r.e.DefaultErrorWebExceptionHandler: Failed to handle request [GET http://localhost:8081/carsss]: 404 NOT_FOUND

rstoyanchev

9

另请参阅https://github.com/spring-projects/spring-framework/wiki/Logging

philwebb

3

当涉及错误映射时，会出现以下输出：

[reactor-http-server-epoll-6] 54:52 o.s.w.s.a.HttpWebHandlerAdapter: [83b08de0] HTTP GET "/carsss", headers={masked}
[reactor-http-server-epoll-6] 54:52 o.s.w.r.h.SimpleUrlHandlerMapping: [83b08de0] Mapped to ResourceWebHandler ["classpath:/META-INF/resources/", "classpath:/resources/", "classpath:/static/", "classpath:/public/"]
[reactor-http-server-epoll-6] 54:52 o.s.w.r.r.ResourceWebHandler: [83b08de0] Resource not found
[reactor-http-server-epoll-6] 54:52 o.s.w.r.f.s.RouterFunctions: [83b08de0] Matched org.springframework.web.reactive.function.server.RequestPredicates$$Lambda$659/369798142@1b4d833b
[reactor-http-server-epoll-6] 54:52 o.s.b.a.w.r.e.DefaultErrorWebExceptionHandler: Failed to handle request [GET http://localhost:8081/carsss]: 404 NOT_FOUND
[reactor-http-server-epoll-6] 54:52 o.s.w.HTTP: [83b08de0] Encoding [{timestamp=Tue Jul 17 08:54:52 EDT 2018, path=/carsss, status=404, error=Not Found, message=null, trace=org.springframework.web.server.ResponseStatusException: 404 NOT_FOUND
...
long stack trace here...
...
[reactor-http-server-epoll-6] 54:52 o.s.w.s.a.HttpWebHandlerAdapter: [83b08de0] Completed 404 NOT_FOUND, headers={masked}
[reactor-http-server-epoll-6] 54:52 o.s.w.HTTP: [83b08de0] Handling completed

请注意 Spring 框架中 TRACE 级别记录的“Matched ... RequestPredicate”消息。目前还不清楚发生了什么是错误映射。这将有助于 a) 在这之前有一条额外的消息，其中显示“路由错误”或“映射错误”之类的内容，b) 也许谓词可以被重构为实际的内部类而不是 lambda，因此它出现在更可读的名称，甚至是一个 toString 方法来选择名称。

rstoyanchev

7

我刚刚对我的工作副本应用了以下更改：

devtools 启用 DEBUG 日志记录"org.springframework.web"
更新DefaultErrorWebExceptionHandler以与框架更改（日志前缀等）保持一致

Spring WebFlux

给定以下控制器，我测试了每个端点以查看日志记录输出。

@RestController
public class HomeController {

    @GetMapping("/")
    public Mono<String> greet(@RequestParam String name) {
        return Mono.just("Hello, " + name);
    }

    @GetMapping("/boom")
    public Mono<String> boom() {
        return Mono.error(new IllegalArgumentException("Something illegal"));
    }

    @GetMapping("/status")
    public Mono<String> status() {
        return Mono.error(new ResponseStatusException(HttpStatus.BAD_REQUEST));
    }
}

23:01:40.095 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Included patterns for restart : []
23:01:40.102 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Excluded patterns for restart : [/spring-boot-starter-[\w-]+/, /spring-boot/target/classes/, /spring-boot-starter/target/classes/, /spring-boot-devtools/target/classes/, /spring-boot-actuator/target/classes/, /spring-boot-autoconfigure/target/classes/]
23:01:40.102 [main] DEBUG org.springframework.boot.devtools.restart.ChangeableUrls - Matching URLs for reloading : [file:/Users/bclozel/workspace/tmp/demo/target/classes/]
sun.reflect.ReflectionFactory@498d318c

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::  (v2.1.0.BUILD-SNAPSHOT)

2018-07-26 23:01:40.467  INFO 8111 --- [  restartedMain] com.example.demo.DemoApplication         : Starting DemoApplication on Brians-MacBook-Pro.local with PID 8111 (/Users/bclozel/workspace/tmp/demo/target/classes started by bclozel in /Users/bclozel/workspace/tmp/demo)
2018-07-26 23:01:40.469  INFO 8111 --- [  restartedMain] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2018-07-26 23:01:42.216 DEBUG 8111 --- [  restartedMain] s.w.r.r.m.a.RequestMappingHandlerMapping : 3 mappings in 'requestMappingHandlerMapping'
2018-07-26 23:01:42.245 DEBUG 8111 --- [  restartedMain] o.s.w.r.handler.SimpleUrlHandlerMapping  : Patterns [/webjars/**, /**] in 'resourceHandlerMapping'
2018-07-26 23:01:42.541  INFO 8111 --- [  restartedMain] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 15 endpoint(s) beneath base path '/actuator'
2018-07-26 23:01:42.631 DEBUG 8111 --- [  restartedMain] o.s.w.r.r.m.a.ControllerMethodResolver   : ControllerAdvice beans: none
2018-07-26 23:01:42.699 DEBUG 8111 --- [  restartedMain] o.s.w.s.adapter.HttpWebHandlerAdapter    : enableLoggingRequestDetails='false': form data and headers will be masked to prevent unsafe logging of potentially sensitive data
2018-07-26 23:01:42.943  INFO 8111 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2018-07-26 23:01:43.083  INFO 8111 --- [  restartedMain] o.s.b.web.embedded.netty.NettyWebServer  : Netty started on port(s): 8080
2018-07-26 23:01:43.088  INFO 8111 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 2.97 seconds (JVM running for 3.885)
2018-07-26 23:01:48.170 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] HTTP GET "/?name=Boot"
2018-07-26 23:01:48.203 DEBUG 8111 --- [ctor-http-nio-2] s.w.r.r.m.a.RequestMappingHandlerMapping : [2840b753] Mapped to public reactor.core.publisher.Mono<java.lang.String> com.example.demo.HomeController.greet(java.lang.String)
2018-07-26 23:01:48.219 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : Using 'text/html' given [text/html, application/xhtml+xml, image/webp, image/apng, application/xml;q=0.9, */*;q=0.8] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*]
2018-07-26 23:01:48.220 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : [2840b753] 0..1 [java.lang.String]
2018-07-26 23:01:48.222 DEBUG 8111 --- [ctor-http-nio-2] o.s.core.codec.CharSequenceEncoder       : [2840b753] Writing 'Hello, Boot'
2018-07-26 23:01:48.236 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] Completed 200 OK
2018-07-26 23:01:51.067 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] HTTP GET "/"
2018-07-26 23:01:51.072 DEBUG 8111 --- [ctor-http-nio-2] s.w.r.r.m.a.RequestMappingHandlerMapping : [2840b753] Mapped to public reactor.core.publisher.Mono<java.lang.String> com.example.demo.HomeController.greet(java.lang.String)
2018-07-26 23:01:51.083 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.r.method.InvocableHandlerMethod  : [2840b753] Could not resolve parameter [0] in public reactor.core.publisher.Mono<java.lang.String> com.example.demo.HomeController.greet(java.lang.String): 400 BAD_REQUEST "Required String parameter 'name' is not present"
2018-07-26 23:01:51.131 DEBUG 8111 --- [ctor-http-nio-2] org.springframework.web.HttpLogging      : [2840b753] Resolved [ServerWebInputException: 400 BAD_REQUEST "Required String parameter 'name' is not present"] for HTTP GET /
2018-07-26 23:01:51.135 DEBUG 8111 --- [ctor-http-nio-2] o.s.core.codec.CharSequenceEncoder       : [2840b753] Writing '<html><body><h1>Whitelabel Error Page</h1><p>This application has no configured error view, so you are seeing this as a fallback.</p><div id='created'>Thu Jul 26 23:01:51 CEST 2018</div><div>There was an unexpected error (type=Bad Request, status=400).</div><div>Required String parameter &#39;name&#39; is not present</div></body></html>'
2018-07-26 23:01:51.136 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] Completed 400 BAD_REQUEST
2018-07-26 23:01:55.403 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] HTTP GET "/status"
2018-07-26 23:01:55.407 DEBUG 8111 --- [ctor-http-nio-2] s.w.r.r.m.a.RequestMappingHandlerMapping : [2840b753] Mapped to public reactor.core.publisher.Mono<java.lang.String> com.example.demo.HomeController.status()
2018-07-26 23:01:55.408 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : Using 'text/html' given [text/html, application/xhtml+xml, image/webp, image/apng, application/xml;q=0.9, */*;q=0.8] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*]
2018-07-26 23:01:55.408 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : [2840b753] 0..1 [java.lang.String]
2018-07-26 23:01:55.432 DEBUG 8111 --- [ctor-http-nio-2] org.springframework.web.HttpLogging      : [2840b753] Resolved [ResponseStatusException: 400 BAD_REQUEST] for HTTP GET /status
2018-07-26 23:01:55.432 DEBUG 8111 --- [ctor-http-nio-2] o.s.core.codec.CharSequenceEncoder       : [2840b753] Writing '<html><body><h1>Whitelabel Error Page</h1><p>This application has no configured error view, so you are seeing this as a fallback.</p><div id='created'>Thu Jul 26 23:01:55 CEST 2018</div><div>There was an unexpected error (type=Bad Request, status=400).</div></body></html>'
2018-07-26 23:01:55.434 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] Completed 400 BAD_REQUEST
2018-07-26 23:01:58.269 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] HTTP GET "/boom"
2018-07-26 23:01:58.272 DEBUG 8111 --- [ctor-http-nio-2] s.w.r.r.m.a.RequestMappingHandlerMapping : [2840b753] Mapped to public reactor.core.publisher.Mono<java.lang.String> com.example.demo.HomeController.boom()
2018-07-26 23:01:58.273 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : Using 'text/html' given [text/html, application/xhtml+xml, image/webp, image/apng, application/xml;q=0.9, */*;q=0.8] and supported [text/plain;charset=UTF-8, text/event-stream, text/plain;charset=UTF-8, */*]
2018-07-26 23:01:58.273 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : [2840b753] 0..1 [java.lang.String]
2018-07-26 23:01:58.293 DEBUG 8111 --- [ctor-http-nio-2] org.springframework.web.HttpLogging      : [2840b753] Resolved [IllegalArgumentException: Something illegal] for HTTP GET /boom
2018-07-26 23:01:58.294 DEBUG 8111 --- [ctor-http-nio-2] o.s.core.codec.CharSequenceEncoder       : [2840b753] Writing '<html><body><h1>Whitelabel Error Page</h1><p>This application has no configured error view, so you are seeing this as a fallback.</p><div id='created'>Thu Jul 26 23:01:58 CEST 2018</div><div>There was an unexpected error (type=Internal Server Error, status=500).</div><div>Something illegal</div></body></html>'
2018-07-26 23:01:58.295 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] Completed 500 INTERNAL_SERVER_ERROR
2018-07-26 23:02:01.861 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] HTTP GET "/notfound"
2018-07-26 23:02:01.865 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.handler.SimpleUrlHandlerMapping  : [2840b753] Mapped to ResourceWebHandler ["classpath:/META-INF/resources/", "classpath:/resources/", "classpath:/static/", "classpath:/public/"]
2018-07-26 23:02:01.867 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.r.resource.ResourceWebHandler      : [2840b753] Resource not found
2018-07-26 23:02:01.880 DEBUG 8111 --- [ctor-http-nio-2] org.springframework.web.HttpLogging      : [2840b753] Resolved [ResponseStatusException: 404 NOT_FOUND] for HTTP GET /notfound
2018-07-26 23:02:01.881 DEBUG 8111 --- [ctor-http-nio-2] o.s.core.codec.CharSequenceEncoder       : [2840b753] Writing '<html><body><h1>Whitelabel Error Page</h1><p>This application has no configured error view, so you are seeing this as a fallback.</p><div id='created'>Thu Jul 26 23:02:01 CEST 2018</div><div>There was an unexpected error (type=Not Found, status=404).</div></body></html>'
2018-07-26 23:02:01.882 DEBUG 8111 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [2840b753] Completed 404 NOT_FOUND

春季MVC

Spring MVC 也是如此

@RestController
public class MvcHomeController {

    @GetMapping("/")
    public String greet(@RequestParam String name) {
        return "Hello, " + name;
    }

    @GetMapping("/boom")
    public String boom() {
        throw new IllegalArgumentException("Something illegal");
    }

    @GetMapping("/status")
    public String status() {
        throw new ResponseStatusException(HttpStatus.BAD_REQUEST);
    }
}

/Library/Java/JavaVirtualMachines/jdk-9.0.1.jdk/Contents/Home/bin/java -XX:TieredStopAtLevel=1 -noverify -Dspring.output.ansi.enabled=always -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=56431 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=127.0.0.1 -Dspring.liveBeansView.mbeanDomain -Dspring.application.admin.enabled=true "-javaagent:/Users/bclozel/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-1/182.3684.101/IntelliJ IDEA 2018.2 EAP.app/Contents/lib/idea_rt.jar=56432:/Users/bclozel/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-1/182.3684.101/IntelliJ IDEA 2018.2 EAP.app/Contents/bin" -Dfile.encoding=UTF-8 -classpath /Users/bclozel/workspace/tmp/demo/target/classes:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter-webflux/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-webflux-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter-logging/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-logging-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar:/Users/bclozel/.m2/repository/ch/qos/logback/logback-core/1.2.3/logback-core-1.2.3.jar:/Users/bclozel/.m2/repository/org/apache/logging/log4j/log4j-to-slf4j/2.11.0/log4j-to-slf4j-2.11.0.jar:/Users/bclozel/.m2/repository/org/apache/logging/log4j/log4j-api/2.11.0/log4j-api-2.11.0.jar:/Users/bclozel/.m2/repository/org/slf4j/jul-to-slf4j/1.7.25/jul-to-slf4j-1.7.25.jar:/Users/bclozel/.m2/repository/javax/annotation/javax.annotation-api/1.3.2/javax.annotation-api-1.3.2.jar:/Users/bclozel/.m2/repository/org/yaml/snakeyaml/1.21/snakeyaml-1.21.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter-json/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-json-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.9.6/jackson-databind-2.9.6.jar:/Users/bclozel/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.9.0/jackson-annotations-2.9.0.jar:/Users/bclozel/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.9.6/jackson-core-2.9.6.jar:/Users/bclozel/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-jdk8/2.9.6/jackson-datatype-jdk8-2.9.6.jar:/Users/bclozel/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-jsr310/2.9.6/jackson-datatype-jsr310-2.9.6.jar:/Users/bclozel/.m2/repository/com/fasterxml/jackson/module/jackson-module-parameter-names/2.9.6/jackson-module-parameter-names-2.9.6.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter-reactor-netty/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-reactor-netty-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/io/projectreactor/netty/reactor-netty/0.8.0.M1/reactor-netty-0.8.0.M1.jar:/Users/bclozel/.m2/repository/io/netty/netty-codec-http/4.1.27.Final/netty-codec-http-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-codec/4.1.27.Final/netty-codec-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-codec-http2/4.1.27.Final/netty-codec-http2-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-handler/4.1.27.Final/netty-handler-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-buffer/4.1.27.Final/netty-buffer-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-transport/4.1.27.Final/netty-transport-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-resolver/4.1.27.Final/netty-resolver-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-handler-proxy/4.1.27.Final/netty-handler-proxy-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-codec-socks/4.1.27.Final/netty-codec-socks-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-transport-native-epoll/4.1.27.Final/netty-transport-native-epoll-4.1.27.Final-linux-x86_64.jar:/Users/bclozel/.m2/repository/io/netty/netty-common/4.1.27.Final/netty-common-4.1.27.Final.jar:/Users/bclozel/.m2/repository/io/netty/netty-transport-native-unix-common/4.1.27.Final/netty-transport-native-unix-common-4.1.27.Final.jar:/Users/bclozel/.m2/repository/org/hibernate/validator/hibernate-validator/6.0.11.Final/hibernate-validator-6.0.11.Final.jar:/Users/bclozel/.m2/repository/javax/validation/validation-api/2.0.1.Final/validation-api-2.0.1.Final.jar:/Users/bclozel/.m2/repository/org/jboss/logging/jboss-logging/3.3.2.Final/jboss-logging-3.3.2.Final.jar:/Users/bclozel/.m2/repository/com/fasterxml/classmate/1.3.4/classmate-1.3.4.jar:/Users/bclozel/.m2/repository/org/springframework/spring-web/5.1.0.RC1/spring-web-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/org/springframework/spring-beans/5.1.0.RC1/spring-beans-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/org/springframework/spring-webflux/5.1.0.RC1/spring-webflux-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/io/projectreactor/reactor-core/3.2.0.M3/reactor-core-3.2.0.M3.jar:/Users/bclozel/.m2/repository/org/reactivestreams/reactive-streams/1.0.2/reactive-streams-1.0.2.jar:/Users/bclozel/.m2/repository/org/synchronoss/cloud/nio-multipart-parser/1.1.0/nio-multipart-parser-1.1.0.jar:/Users/bclozel/.m2/repository/org/slf4j/slf4j-api/1.7.25/slf4j-api-1.7.25.jar:/Users/bclozel/.m2/repository/org/synchronoss/cloud/nio-stream-storage/1.1.3/nio-stream-storage-1.1.3.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter-web/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-web-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter-tomcat/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-tomcat-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/apache/tomcat/embed/tomcat-embed-core/9.0.10/tomcat-embed-core-9.0.10.jar:/Users/bclozel/.m2/repository/org/apache/tomcat/embed/tomcat-embed-el/9.0.10/tomcat-embed-el-9.0.10.jar:/Users/bclozel/.m2/repository/org/apache/tomcat/embed/tomcat-embed-websocket/9.0.10/tomcat-embed-websocket-9.0.10.jar:/Users/bclozel/.m2/repository/org/springframework/spring-webmvc/5.1.0.RC1/spring-webmvc-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/org/springframework/spring-aop/5.1.0.RC1/spring-aop-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/org/springframework/spring-context/5.1.0.RC1/spring-context-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/org/springframework/spring-expression/5.1.0.RC1/spring-expression-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-starter-actuator/2.1.0.BUILD-SNAPSHOT/spring-boot-starter-actuator-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-actuator-autoconfigure/2.1.0.BUILD-SNAPSHOT/spring-boot-actuator-autoconfigure-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-actuator/2.1.0.BUILD-SNAPSHOT/spring-boot-actuator-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/io/micrometer/micrometer-core/1.0.6/micrometer-core-1.0.6.jar:/Users/bclozel/.m2/repository/org/hdrhistogram/HdrHistogram/2.1.10/HdrHistogram-2.1.10.jar:/Users/bclozel/.m2/repository/org/latencyutils/LatencyUtils/2.0.3/LatencyUtils-2.0.3.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-devtools/2.1.0.BUILD-SNAPSHOT/spring-boot-devtools-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot/2.1.0.BUILD-SNAPSHOT/spring-boot-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/boot/spring-boot-autoconfigure/2.1.0.BUILD-SNAPSHOT/spring-boot-autoconfigure-2.1.0.BUILD-SNAPSHOT.jar:/Users/bclozel/.m2/repository/org/springframework/spring-core/5.1.0.RC1/spring-core-5.1.0.RC1.jar:/Users/bclozel/.m2/repository/org/springframework/spring-jcl/5.1.0.RC1/spring-jcl-5.1.0.RC1.jar com.example.demo.DemoApplication
sun.reflect.ReflectionFactory@1d9b7cce
23:11:04.868 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Included patterns for restart : []
23:11:04.872 [main] DEBUG org.springframework.boot.devtools.settings.DevToolsSettings - Excluded patterns for restart : [/spring-boot-starter-[\w-]+/, /spring-boot/target/classes/, /spring-boot-starter/target/classes/, /spring-boot-devtools/target/classes/, /spring-boot-actuator/target/classes/, /spring-boot-autoconfigure/target/classes/]
23:11:04.872 [main] DEBUG org.springframework.boot.devtools.restart.ChangeableUrls - Matching URLs for reloading : [file:/Users/bclozel/workspace/tmp/demo/target/classes/]
sun.reflect.ReflectionFactory@1d9b7cce

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::  (v2.1.0.BUILD-SNAPSHOT)

2018-07-26 23:11:05.226  INFO 8126 --- [  restartedMain] com.example.demo.DemoApplication         : Starting DemoApplication on Brians-MacBook-Pro.local with PID 8126 (/Users/bclozel/workspace/tmp/demo/target/classes started by bclozel in /Users/bclozel/workspace/tmp/demo)
2018-07-26 23:11:05.230  INFO 8126 --- [  restartedMain] com.example.demo.DemoApplication         : No active profile set, falling back to default profiles: default
2018-07-26 23:11:06.664  INFO 8126 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2018-07-26 23:11:06.681  INFO 8126 --- [  restartedMain] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2018-07-26 23:11:06.682  INFO 8126 --- [  restartedMain] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/9.0.10
2018-07-26 23:11:06.699  INFO 8126 --- [  restartedMain] o.a.catalina.core.AprLifecycleListener   : The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/Users/bclozel/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.]
2018-07-26 23:11:06.776  INFO 8126 --- [  restartedMain] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2018-07-26 23:11:06.776 DEBUG 8126 --- [  restartedMain] o.s.web.context.ContextLoader            : Published root WebApplicationContext as ServletContext attribute with name [org.springframework.web.context.WebApplicationContext.ROOT]
2018-07-26 23:11:06.776  INFO 8126 --- [  restartedMain] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1492 ms
2018-07-26 23:11:07.058  INFO 8126 --- [  restartedMain] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'characterEncodingFilter' to: [/*]
2018-07-26 23:11:07.059  INFO 8126 --- [  restartedMain] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'webMvcMetricsFilter' to: [/*]
2018-07-26 23:11:07.059  INFO 8126 --- [  restartedMain] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2018-07-26 23:11:07.059  INFO 8126 --- [  restartedMain] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2018-07-26 23:11:07.059  INFO 8126 --- [  restartedMain] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'requestContextFilter' to: [/*]
2018-07-26 23:11:07.059  INFO 8126 --- [  restartedMain] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'httpTraceFilter' to: [/*]
2018-07-26 23:11:07.059  INFO 8126 --- [  restartedMain] o.s.b.w.servlet.ServletRegistrationBean  : Servlet dispatcherServlet mapped to [/]
2018-07-26 23:11:07.156 DEBUG 8126 --- [  restartedMain] o.s.w.s.handler.SimpleUrlHandlerMapping  : Patterns [/**/favicon.ico] in 'faviconHandlerMapping'
2018-07-26 23:11:07.224 DEBUG 8126 --- [  restartedMain] s.w.s.m.m.a.RequestMappingHandlerAdapter : ControllerAdvice beans: 0 @ModelAttribute, 0 @InitBinder, 1 RequestBodyAdvice, 1, ResponseBodyAdvice
2018-07-26 23:11:07.268 DEBUG 8126 --- [  restartedMain] s.w.s.m.m.a.RequestMappingHandlerMapping : 5 mappings in 'requestMappingHandlerMapping'
2018-07-26 23:11:07.277 DEBUG 8126 --- [  restartedMain] o.s.w.s.handler.SimpleUrlHandlerMapping  : Patterns [/webjars/**, /**] in 'resourceHandlerMapping'
2018-07-26 23:11:07.290 DEBUG 8126 --- [  restartedMain] .m.m.a.ExceptionHandlerExceptionResolver : ControllerAdvice beans: 0 @ExceptionHandler, 1 ResponseBodyAdvice
2018-07-26 23:11:07.311  INFO 8126 --- [  restartedMain] o.s.b.a.w.s.WelcomePageHandlerMapping    : Adding welcome page: class path resource [static/index.html]
2018-07-26 23:11:07.562  INFO 8126 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2018-07-26 23:11:07.568  INFO 8126 --- [  restartedMain] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 15 endpoint(s) beneath base path '/actuator'
2018-07-26 23:11:07.648  INFO 8126 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2018-07-26 23:11:07.653  INFO 8126 --- [  restartedMain] com.example.demo.DemoApplication         : Started DemoApplication in 2.765 seconds (JVM running for 3.603)
2018-07-26 23:11:07.762  INFO 8126 --- [on(2)-127.0.0.1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2018-07-26 23:11:07.763  INFO 8126 --- [on(2)-127.0.0.1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2018-07-26 23:11:07.763 DEBUG 8126 --- [on(2)-127.0.0.1] o.s.web.servlet.DispatcherServlet        : Detected StandardServletMultipartResolver
2018-07-26 23:11:07.768 DEBUG 8126 --- [on(2)-127.0.0.1] o.s.web.servlet.DispatcherServlet        : enableLoggingRequestDetails='false': request parameters and headers will be masked to prevent unsafe logging of potentially sensitive data
2018-07-26 23:11:07.768  INFO 8126 --- [on(2)-127.0.0.1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 5 ms
2018-07-26 23:11:13.177 DEBUG 8126 --- [nio-8080-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.greet(java.lang.String)
2018-07-26 23:11:13.183 DEBUG 8126 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : GET "/?name=Boot", parameters={masked}
2018-07-26 23:11:13.186 DEBUG 8126 --- [nio-8080-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.greet(java.lang.String)
2018-07-26 23:11:13.205 DEBUG 8126 --- [nio-8080-exec-1] m.m.a.RequestResponseBodyMethodProcessor : Using 'text/html', given [text/html, application/xhtml+xml, image/webp, image/apng, application/xml;q=0.9, */*;q=0.8] and supported [text/plain, */*, text/plain, */*, application/json, application/*+json, application/json, application/*+json]
2018-07-26 23:11:13.205 DEBUG 8126 --- [nio-8080-exec-1] m.m.a.RequestResponseBodyMethodProcessor : Writing ["Hello, Boot"]
2018-07-26 23:11:13.214 DEBUG 8126 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2018-07-26 23:11:15.789 DEBUG 8126 --- [nio-8080-exec-2] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.greet(java.lang.String)
2018-07-26 23:11:15.790 DEBUG 8126 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : GET "/", parameters={}
2018-07-26 23:11:15.792 DEBUG 8126 --- [nio-8080-exec-2] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.greet(java.lang.String)
2018-07-26 23:11:15.793 DEBUG 8126 --- [nio-8080-exec-2] .w.s.m.m.a.ServletInvocableHandlerMethod : Could not resolve parameter [0] in public java.lang.String com.example.demo.MvcHomeController.greet(java.lang.String): Required String parameter 'name' is not present
2018-07-26 23:11:15.795  WARN 8126 --- [nio-8080-exec-2] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.bind.MissingServletRequestParameterException: Required String parameter 'name' is not present]
2018-07-26 23:11:15.796 DEBUG 8126 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : Completed 400 BAD_REQUEST
2018-07-26 23:11:15.799 DEBUG 8126 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : "ERROR" dispatch for GET "/error", parameters={}
2018-07-26 23:11:15.805 DEBUG 8126 --- [nio-8080-exec-2] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-07-26 23:11:15.816 DEBUG 8126 --- [nio-8080-exec-2] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, text/html;q=0.8]
2018-07-26 23:11:15.827 DEBUG 8126 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : Exiting from "ERROR" dispatch, status 400
2018-07-26 23:11:18.420 DEBUG 8126 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.status()
2018-07-26 23:11:18.421 DEBUG 8126 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet        : GET "/status", parameters={}
2018-07-26 23:11:18.423 DEBUG 8126 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.status()
2018-07-26 23:11:18.424  WARN 8126 --- [nio-8080-exec-3] .w.s.m.a.ResponseStatusExceptionResolver : Resolved [org.springframework.web.server.ResponseStatusException: 400 BAD_REQUEST]
2018-07-26 23:11:18.425 DEBUG 8126 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet        : Completed 400 BAD_REQUEST
2018-07-26 23:11:18.425 DEBUG 8126 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet        : "ERROR" dispatch for GET "/error", parameters={}
2018-07-26 23:11:18.427 DEBUG 8126 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-07-26 23:11:18.437 DEBUG 8126 --- [nio-8080-exec-3] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, text/html;q=0.8]
2018-07-26 23:11:18.437 DEBUG 8126 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet        : Exiting from "ERROR" dispatch, status 400
2018-07-26 23:11:22.188 DEBUG 8126 --- [nio-8080-exec-4] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.boom()
2018-07-26 23:11:22.189 DEBUG 8126 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : GET "/boom", parameters={}
2018-07-26 23:11:22.190 DEBUG 8126 --- [nio-8080-exec-4] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String com.example.demo.MvcHomeController.boom()
2018-07-26 23:11:22.193 DEBUG 8126 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Failed to complete request: java.lang.IllegalArgumentException: Something illegal
2018-07-26 23:11:22.201 ERROR 8126 --- [nio-8080-exec-4] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.IllegalArgumentException: Something illegal] with root cause

java.lang.IllegalArgumentException: Something illegal
    at com.example.demo.MvcHomeController.boom(MvcHomeController.java:22) ~[classes/:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Method.java:564) ~[na:na]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:207) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:880) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:785) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1041) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:942) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:998) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:890) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:875) ~[spring-webmvc-5.1.0.RC1.jar:5.1.0.RC1]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:90) ~[spring-boot-actuator-2.1.0.BUILD-SNAPSHOT.jar:2.1.0.BUILD-SNAPSHOT]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:112) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:155) ~[spring-boot-actuator-2.1.0.BUILD-SNAPSHOT.jar:2.1.0.BUILD-SNAPSHOT]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:123) ~[spring-boot-actuator-2.1.0.BUILD-SNAPSHOT.jar:2.1.0.BUILD-SNAPSHOT]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:108) ~[spring-boot-actuator-2.1.0.BUILD-SNAPSHOT.jar:2.1.0.BUILD-SNAPSHOT]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.1.0.RC1.jar:5.1.0.RC1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199) ~[tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:491) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:764) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1388) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [na:na]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.10.jar:9.0.10]
    at java.base/java.lang.Thread.run(Thread.java:844) [na:na]

2018-07-26 23:11:22.203 DEBUG 8126 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : "ERROR" dispatch for GET "/error", parameters={}
2018-07-26 23:11:22.204 DEBUG 8126 --- [nio-8080-exec-4] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-07-26 23:11:22.210 DEBUG 8126 --- [nio-8080-exec-4] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, text/html;q=0.8]
2018-07-26 23:11:22.210 DEBUG 8126 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Exiting from "ERROR" dispatch, status 500
2018-07-26 23:11:25.666 DEBUG 8126 --- [nio-8080-exec-5] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped to ResourceHttpRequestHandler ["classpath:/META-INF/resources/", "classpath:/resources/", "classpath:/static/", "classpath:/public/", "/"]
2018-07-26 23:11:25.667 DEBUG 8126 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : GET "/notfound", parameters={}
2018-07-26 23:11:25.668 DEBUG 8126 --- [nio-8080-exec-5] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped to ResourceHttpRequestHandler ["classpath:/META-INF/resources/", "classpath:/resources/", "classpath:/static/", "classpath:/public/", "/"]
2018-07-26 23:11:25.669 DEBUG 8126 --- [nio-8080-exec-5] o.s.w.s.r.ResourceHttpRequestHandler     : Resource not found
2018-07-26 23:11:25.669 DEBUG 8126 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Completed 404 NOT_FOUND
2018-07-26 23:11:25.669 DEBUG 8126 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : "ERROR" dispatch for GET "/error", parameters={}
2018-07-26 23:11:25.670 DEBUG 8126 --- [nio-8080-exec-5] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-07-26 23:11:25.674 DEBUG 8126 --- [nio-8080-exec-5] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, text/html;q=0.8]
2018-07-26 23:11:25.675 DEBUG 8126 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Exiting from "ERROR" dispatch, status 404

可能的改进

调低用于调度程序 servlet 注册的 Tomcat 日志记录（请参阅现有日志记录配置）
我们可以对完整的异常堆栈跟踪做些什么吗？
重新编写在 Spring Boot 中注册 Servlet Filter 时写入的日志（我们可以将所有日志重新组合到一行中吗？）

bclozel

3

整洁的！

那么也org.springframework.http和呢org.springframework.core.codec？这将消除通用的后备日志记录到o.s.w.HttpLogging.

非常小，但这似乎与昨天的提交相比有一些但不是全部更改https://github.com/spring-projects/spring-framework/commit/14d0fee86c207df1d88ac63ff159d06337f34817。例如，ContextLoader消息是以前的消息，而FrameworkServlet消息是当前的消息。这几乎就像 spring-web 是一个过时的快照。

堆栈跟踪来自 Tomcat。也许 FrameworkServlet 可以停止异常，或者有一个属性来停止异常并将状态设置为 500。我希望，这仍然应该触发错误调度？

额外的调度程序 servlet init 来自通过编写的 getServletContext().getLog()FrameworkServlet 。我想知道我们是否真的需要登录到这两个地方。

rstoyanchev

5

org.springframework.http我刚刚在配置和org.springframework.core.codec调试后更新了示例日志。我的示例应用程序使用的是 5.1.0.RC1。在其中添加断点后，似乎未启用调试 - 我是否org.springframework.context.support也应该添加到调试列表中？

记录请求详细信息

正如您所说，现在有多种方法可以配置是否记录请求详细信息（标头和正文，可能包含敏感信息）：

使用 Spring MVC，dispatcherServlet.setEnableLoggingRequestDetails(true)
使用 Spring WebFlux，直接在编解码器上configurer.defaultCodecs().enableLoggingRequestDetails(true)- 这适用于服务器和WebClient

我们应该支持它们作为配置属性（并决定是否要使用开发工具默认启用它们）。

spring.mvc.log-request-details=true
spring.webflux.log-request-details=true

明显的解决方案有点奇怪，因为一个只是服务器，另一个是服务器和客户端，即使它们正在做（几乎）相同的事情。另外，由于 webflux 是在编解码器上完成的，因此该解决方案在CodecsAutoConfiguration和之间创建了依赖关系WebFluxProperties，这感觉有点奇怪。

我们还可以考虑使用另一个命名空间的不同解决方案，以深入了解应用程序。我不知道这是否真的值得一个新的命名空间，但我想知道是否会出现更多类似的事情。

spring.insights.web.log-request-details=true

我将此问题标记为引起团队注意，尤其是最后一点。

bclozel

7

spring.insights.web.log-request-details（注意web命名空间）对我来说比两个单独的属性更好。insights是某个名字@bclozel，我在讨论该功能时想到的。我不知道是否值得为此引入一个新的“高级”概念，但我宁愿将其放在专用的命名空间中，而不是到处都有一些属性。

snicoll

4

我认为这也应该可以更轻松地涵盖 Spring MVC Controller + WebClient 场景。

rstoyanchev

5

https://jira.spring.io/browse/SPR-17100

rstoyanchev

8

SPR-17100现已解决，包括一个DispatcherServlet名为“shouldHandleFailure”的新属性，该属性不会让异常传播（并由容器记录），而是sendError(500)使用异常信息调用和设置 Servlet 请求属性。本质上与任何其他 Spring MVC 解决的异常结果相同。

我建议在 Spring Boot 中将该属性设置为“true”，并且我认为没有理由必须自定义它。 Servlet 规范规定在以下情况下使用错误页面：

a servlet or filter calls sendError on the response for
specific status codes, or if the servlet generates an exception or error that propagates
to the container.

我用 Boot 应用程序尝试了这一点，它按预期工作，即 Tomcat 不再记录堆栈跟踪。

rstoyanchev

0

调度程序 servlet 处理失败的问题与 Jersey 默认情况下的问题相同。请参阅#12995 和此更改，其中记录了如何阻止 Jersey 处理失败，以便 Spring Security 在使用方法安全性时可以看到它。

wilkinsona

2

在 Boot 应用程序中，将异常传播到容器会导致异常在由 ErrorController 转发和处理之前被不必要地记录下来。更改的目标是消除不必要的堆栈跟踪。

我setStatus确实从#12995 中提到的开始，但这并没有传播到引导的错误映射。我现在可以看到这sendError可以阻止过滤器处理异常。

可以说，这不是一个需要DispatcherServlet尝试解决的问题。考虑到这些复杂性，我将恢复更改。也许 Spring Boot 可以在最前面插入一个过滤器来执行相同的操作。这似乎更合适，因为尝试抑制堆栈跟踪的原因是因为我们知道异常将由引导的错误映射处理。有人还可能认为，如果存在错误映射，Tomcat 不应该记录堆栈跟踪，但其他容器也可能会这样做。

rstoyanchev

8

感谢@wilkinsona 和@rstoyanchev！我暂时关闭这个问题，我们将在单独的线程中讨论过滤器的排列。

bclozel

[spring-projects/spring-boot]微调和审查日志记录输出

回答

相关问题