配置重新加载后 Logback 停止记录
我们正在评估 Logback 在多服务器 Weblogic 环境中的使用。在一台机器上，我们有两个在同一个 Weblogic 域上运行的 Weblogic 服务器实例（基本上是两个独立的 JVM 进程）。服务器记录到同一日志文件 (application.log)。两台服务器的 Logback 配置 (logback.xml) 相同（如下所示）：
<configuration scan="true" debug="true">
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>log/application.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>log/application.%d{yyyy-MM-dd}.log</FileNamePattern>
</rollingPolicy>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>%d{HH:mm:ss.SSS} [%31.31logger] [%-5level] [%28.-28thread] %msg %xEx %n</pattern>
</encoder>
</appender>
<logger name="org" level="ERROR"/>
<root level="DEBUG">
<appender-ref ref="FILE" />
</root>
</configuration>
一切正常，直到编辑配置（例如更改根日志记录级别或添加新记录器），之后日志记录完全停止。日志中没有打印任何内容，控制台中也看不到 Logback 错误消息。 Logback 已经处于调试模式，通过在服务器启动时将以下内容写入每个服务器的控制台来验证：
18:06:37,949 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
18:06:37,951 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
18:06:37,957 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/opt/bea10/user_projects/KG/resources/config/logback.xml]
18:06:39,457 |-INFO in ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter@158ef4f - Will scan for changes in file [/opt/bea10/user_projects/KG/resources/config/logback.xml] every 60 seconds.
18:06:39,457 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
18:06:39,471 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
18:06:39,556 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
18:06:40,061 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [rollingPolicy] on top of the object stack.
18:06:40,533 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
18:06:40,563 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern log/application.%d{yyyy-MM-dd}.log for the active file
18:06:40,652 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern 'log/application.%d{yyyy-MM-dd}.log'.
18:06:40,652 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
18:06:40,654 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Wed Oct 20 17:43:20 EEST 2010
18:06:40,685 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [encoder] on top of the object stack.
18:06:41,256 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: log/application.log
18:06:41,257 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [log/application.log]
18:06:41,307 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org] to ERROR
18:06:41,307 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org] to true
18:06:41,307 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG
18:06:41,308 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
18:06:41,351 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
Logback 的版本是 0.9.24，slf4j 是 1.6.0，Weblogic 是 10.3（怀疑是否重要），Java 是1.6.0_12。操作系统是Solaris。我什至尝试放置 Java 选项
-XX:-UseVMInterruptibleIO
，因为这被建议解决 Solaris 上的 Logback 问题
有办法让这项工作发挥作用吗？让两个服务器写入同一个日志文件是不是一个坏主意？
We are evaluating the use of Logback in a multi-server Weblogic environment. On one machine we have two Weblogic server instances (basically two separate JVM processes) running on a same Weblogic domain. The servers log to the same log file (application.log). The Logback configuration (logback.xml) is the same for both servers (shown below):
<configuration scan="true" debug="true">
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>log/application.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>log/application.%d{yyyy-MM-dd}.log</FileNamePattern>
</rollingPolicy>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>%d{HH:mm:ss.SSS} [%31.31logger] [%-5level] [%28.-28thread] %msg %xEx %n</pattern>
</encoder>
</appender>
<logger name="org" level="ERROR"/>
<root level="DEBUG">
<appender-ref ref="FILE" />
</root>
</configuration>
Everything works fine until the configuration is edited (e.g. the root logging level changed or a new logger added) after which logging stops completely. Nothing gets printed in the logs, and no Logback error message is visible in the console either. Logback is in debug mode already, which is verified by the following being written to each server's console upon server startup:
18:06:37,949 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
18:06:37,951 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
18:06:37,957 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/opt/bea10/user_projects/KG/resources/config/logback.xml]
18:06:39,457 |-INFO in ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter@158ef4f - Will scan for changes in file [/opt/bea10/user_projects/KG/resources/config/logback.xml] every 60 seconds.
18:06:39,457 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
18:06:39,471 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
18:06:39,556 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
18:06:40,061 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [rollingPolicy] on top of the object stack.
18:06:40,533 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
18:06:40,563 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern log/application.%d{yyyy-MM-dd}.log for the active file
18:06:40,652 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern 'log/application.%d{yyyy-MM-dd}.log'.
18:06:40,652 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
18:06:40,654 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Wed Oct 20 17:43:20 EEST 2010
18:06:40,685 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Pushing component [encoder] on top of the object stack.
18:06:41,256 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: log/application.log
18:06:41,257 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [log/application.log]
18:06:41,307 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org] to ERROR
18:06:41,307 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org] to true
18:06:41,307 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG
18:06:41,308 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
18:06:41,351 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
The version of Logback is 0.9.24, slf4j is 1.6.0, Weblogic is 10.3 (doubt if that matters) and Java is 1.6.0_12. OS is Solaris. I even tried putting the Java option
-XX:-UseVMInterruptibleIO
because this was suggested to a Logback problem on Solaris here, but this did not help.
Is there a way to make this work? Is it a bad idea altogether to have the two servers to write to the same log file?
如果你对这篇内容有疑问，欢迎到本站社区发帖提问 参与讨论，获取更多帮助，或者扫码二维码加入 Web 技术交流群。
绑定邮箱获取回复消息
由于您还没有绑定你的真实邮箱，如果其他用户或者作者回复了您的评论，将不能在第一时间通知您！
发布评论
评论（3）
正如 Alex Poole 之前提到的，谨慎模式应该会有所帮助。还强烈建议注册一个状态监听器，例如 OnConsoleStatusListener，这样就不会出现问题可以报告在应用程序的生命周期内发生的情况（在 logback 初始化之后）。
如果修改后的配置文件不是格式良好，logback 版本 0.0.29 及更高版本将恢复到之前格式良好的配置文件。您没有提到新的配置文件存在格式良好的问题，这就是为什么谨慎模式可能是最相关的响应。
As Alex Poole mentioned earlier, the prudent mode should help. It is also highly recommended to register a status listener, e.g. OnConsoleStatusListener, so that problems occurring during the lifetime of your application, well after logback is initialized, can be reported.
In case the modified configuration file is not well formed logback versions 0.0.29 and later will revert to the previous well-formed configuration file. You did not mention that the new configuration file had a well-formedness problem, si that is why prudent mode is probably the most relevant response.
prudent属性有帮助吗？它增加了开销，但可以解决多个 JVM 的问题。我不确定您的症状是否完全匹配，但可能值得一试。Does the
prudentproperty help? It adds overhead but can work around issues with multiple JVMs. I'm not sure your symptoms quite match, but it might be worth a try.我们有一个类似的问题，有时 logback 会在重新部署应用程序时停止日志记录。因此，我们在每次部署后都会重新启动应用程序服务器。这样问题就解决了。
由于重新启动 Prod 服务器总是很困难，经过进一步调查和搜索，我们发现这是旧版本的 logback 的问题。我们已将版本从 1.1.7 更改为 1.1.10，并解决了该问题
We have a similar issue, sometimes logback stopping the logging when ever application is redeployed. So we are restarting the application server after every deployment. That resolves the issue.
As restarting Prod servers always is difficult, on further investigation and search we found that is it issue with older versions of logback. We have changed version from 1.1.7 to 1.1.10 and it resolved the issue