java - 为什么 Spring 不跟我说话？ (或 : How do I correctly configure Spring logging? )

Question

我的实际问题是 Spring Security 和为身份验证服务器配置 OAuth2，但是为了跟踪我的问题，我希望 Spring 告诉我当请求到达端点时实际发生了什么。我正在使用 Spring Boot 2.0.0-SNAPSHOT 和日志启动程序 spring-boot-starter-log4j2，实际上它似乎工作得很好。我的 log4j2 配置是:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE Configuration>
<Configuration status="WARN">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%-5level%d{MMM dd, yyyy HH:mm:ss.SSS} [%t] %X %logger{36}%n  %msg%n"/>
    </Console>
  <File name="File" fileName="logs/application.log">
    <PatternLayout pattern="%-5level%d{MMM dd, yyyy HH:mm:ss.SSS} [%t] %X %logger{36} %msg%n"/>
  </File>
  </Appenders>
  <Loggers>    
    <Root level="debug">
      <AppenderRef ref="Console"/>
      <AppenderRef ref="File"/>
    </Root>
    <logger name="org.springframework" level="debug" additivity="false">
      <AppenderRef ref="Console"/>
      <AppenderRef ref="File"/>
    </logger>
    <logger name="org.springframework.security" level="debug" additivity="false">
      <AppenderRef ref="Console"/>
      <AppenderRef ref="File"/>
    </logger>
    <logger name="org.hibernate" level="info" additivity="false">
      <AppenderRef ref="Console"/>
      <AppenderRef ref="File"/>
    </logger>
  </Loggers>
</Configuration>

启动应用程序(嵌入式 Tomcat)时，我可以看到配置实际上已被使用，并且 Spring 在此过程中记录了很多内容:

...
INFO Feb 02, 2018 11:31:00.295 [restartedMain] {} org.hibernate.type.BasicTypeRegistry
  HHH000270: Type registration [java.util.UUID] overrides previous : org.hibernate.type.UUIDBinaryType@41229bd4
INFO Feb 02, 2018 11:31:00.345 [restartedMain] {} org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean
  Initialized JPA EntityManagerFactory for persistence unit 'default'
DEBUG Feb 02, 2018 11:31:00.440 [restartedMain] {} org.springframework.data.jpa.repository.query.JpaQueryFactory
  Looking up query for method findByEmail
...

但是当我向应用程序发送请求以获取接收到 4xx 错误的 Oauth2 访问 token 时，我希望 Spring 告诉我它做了什么，以便我可以找到我的配置错误。但它不记录任何内容。我看到了 Hiberante 的东西和我自己的日志记录，但 Spring 保持沉默。由于 TRACE 配置，我预计会有很多消息。

任何人都可以想象，我做错了什么吗？还是 Spring 根本不健谈？

2018 年 2 月 8 日更新:
看来我的问题与Spring Security有关。我进行了一些调试，并为 Spring Security 和框架的其他部分找到了不同的记录器。
例如在 org.springframework.data.jpa.repository.query.JpaQueryFactorySpring 正在使用记录器 org.apache.logging.slf4j.Log4jLogger(设置为 DEBUG在我的配置中)，但是 Spring 安全使用 org.apache.commons.logging.impl.Jdk14Logger 例如在 org.springframework.security.web.FilterChainProxy (设置尽管我的 log4j2 配置到 INFO)。

所以我尝试调试分配了 FilterChainProxy 记录器的代码。但不幸的是，代码要么从未达到，要么我的断点不起作用。我猜是第二个。

Answer 1

我自己找到了问题的原因:
Spring 广泛使用 slf4J 进行日志记录。为此，我在我的项目中加入了一个桥接器，它运行良好，并在我的问题中生成了日志输出。
但是 Spring Security(可能还有 Spring 的其他部分)使用 Apache Commons Logging 这本身没有问题，因为 Spring 5 带有 spring.jcl 这是从 Apache Commons Logging 到 log4J2 的桥梁之一。
但这里是邪恶的事情:我包含了另一个库，它对 common-logging 具有传递依赖性，因此将“Apache Commons Logging”的直接实现包含到我的项目中。所以我的类路径中有两个不同的 org.apache.commons.logging.LogFactory 类。 Spring security 决定使用 commons-logging 中的实现而不是 spring-jcl 中的实现，当然因此我的 log4j-configuration 不会影响 Spring security 的记录器。

实际上，我所要做的就是在我的构建文件中排除 commons-logging 并让 spring-jcl 再次完成它的工作。