- logback-user - mailman3.qos.ch

Seeking help with Logback-related race condition in Dropwizard
by Evan Meagher 24 Sep '16

24 Sep '16

Greetings Logback community, I'm one of the maintainers of Dropwizard, a Java REST service library. We're dealing with an race condition that may have something to do with Logback and I wanted to reach out to see if our issue smells like anything the Logback team has encountered before. We've been trying to diagnose a small handful of related bugs that all seem to stem from a race condition somewhere within the interaction between Jetty's request-handling lifecycle, Logback's RequestLogImpl, and Logback's async appender functionality. My best assessment of the issue is as follows. Jetty defines a Request class to encapsulate state specific to a single request (i.e. HTTP headers, query parameters, etc). Jetty servers reuse instances of this Request class for each connection (presumably in order to reduce memory pressure), and thus requests have to be recycled <http://download.eclipse.org/jetty/9.3.11.v20160721/apidocs/org/eclipse/jett…> for each individual HTTP request. We seem to get into trouble when Logback's RequestLogImpl is used in conjunction with AsyncAppenderBase. `AccessEvent# prepareForDeferredProcessing` <https://github.com/qos-ch/logback/blob/master/logback-access/src/main/java/…> , which populates the event with request data, is invoked by both of these codepaths. Could it be possible that Jetty's use of a mutable Request object per connection could be getting in the way of asynchronous request logging by Logback? For the complete background, the bug(s) span the following Dropwizard issues: - https://github.com/dropwizard/dropwizard/issues/1672 - https://github.com/dropwizard/dropwizard/issues/1686 - https://github.com/dropwizard/dropwizard/issues/1699 Unfortunately, we don't have a single representative test case to illustrate the issue. In this latter GitHub issue (#1699), Nick Babcock and I traded notes back and forth as we spelunked through Dropwizard, Jetty, and Logback trying to root out the issue, and found that forcing synchronous request logging prevented the inconsistent behavior. Any guidance on Logback usage related to this would be a very helpful. Thanks, -- Evan Meagher

1 0

Re: [logback-user] jira down; ReconfigureOnChangeTask bug
by Stefan.Brozinski＠materna.de 19 Sep '16

19 Sep '16

Ah, now that Jira is up I can see that an issue had already been created. http://jira.qos.ch/browse/LOGBACK-1194 Von: logback-user [mailto:logback-user-bounces@qos.ch] Im Auftrag von ceki Gesendet: Freitag, 16. September 2016 20:44 An: logback users list <logback-user(a)qos.ch> Betreff: Re: [logback-user] jira down; ReconfigureOnChangeTask bug Jira should be up now. Please create a jira issue for the scanPeriod bug. I'll look into it on Tuesday as I am currently traveling. -- Ceki -------- Original message -------- From: Stefan.Brozinski(a)materna.de<mailto:Stefan.Brozinski@materna.de> Date: 2016/09/16 18:41 (GMT+01:00) To: logback-user(a)qos.ch<mailto:logback-user@qos.ch> Subject: [logback-user] jira down; ReconfigureOnChangeTask bug Dear all, just in case you haven’t noticed: jira.qos.ch is currently down (http 503). I would also like to point out that the git commit 1518573 introduced a bug. Having only the „scan“ attribute in the logback configuration without an additional „scanPeriod“ attribute does NOT activate the ReconfigureOnChangeTask. So currently you need to have something like scanPeriod=“60 seconds“ in your logback.xml if you want to have your configuration changes being picked up without having to restart your process. This might also be the reason for the problems that were recently observed by Gaël Marziou. Gaël, does it help to add a scanPeriod to your configuration? Best regards Stefan

1 0

Re: [logback-user] jira down; ReconfigureOnChangeTask bug
by ceki 16 Sep '16

16 Sep '16

Jira should be up now. Please create a jira issue for the scanPeriod bug. I'll look into it on Tuesday as I am currently traveling. --Ceki -------- Original message -------- From: Stefan.Brozinski(a)materna.de Date: 2016/09/16 18:41 (GMT+01:00) To: logback-user(a)qos.ch Subject: [logback-user] jira down; ReconfigureOnChangeTask bug Dear all, just in case you haven’t noticed: jira.qos.ch is currently down (http 503). I would also like to point out that the git commit 1518573 introduced a bug. Having only the „scan“ attribute in the logback configuration without an additional „scanPeriod“ attribute does NOT activate the ReconfigureOnChangeTask. So currently you need to have something like scanPeriod=“60 seconds“ in your logback.xml if you want to have your configuration changes being picked up without having to restart your process. This might also be the reason for the problems that were recently observed by Gaël Marziou. Gaël, does it help to add a scanPeriod to your configuration? Best regards Stefan

1 0

jira down; ReconfigureOnChangeTask bug
by Stefan.Brozinski＠materna.de 16 Sep '16

16 Sep '16

Dear all, just in case you haven't noticed: jira.qos.ch is currently down (http 503). I would also like to point out that the git commit 1518573 introduced a bug. Having only the "scan" attribute in the logback configuration without an additional "scanPeriod" attribute does NOT activate the ReconfigureOnChangeTask. So currently you need to have something like scanPeriod="60 seconds" in your logback.xml if you want to have your configuration changes being picked up without having to restart your process. This might also be the reason for the problems that were recently observed by Gaël Marziou. Gaël, does it help to add a scanPeriod to your configuration? Best regards Stefan

2 1

how to free the logger instance in the loggerCache
by Zhenyi Zhao 24 Aug '16

24 Aug '16

I saw the loggerCache in class LoggerContext is a ConcurrentHashMap, how to free the instance in it.

2 1

Accessing an appender programatically not using a logger
by Gonçalo Luiz 24 Aug '16

24 Aug '16

Hi, I need to access an appender programatically. This appender is present in the configuration XML but the only way to access it seems to be through loggers that hold a reference to it. I would like to directly access it (for example by its name) without having to know which loggers it might be attached to. Is there a way to do this ? Gonçalo Luiz

1 0

Reconfiguration with file configuration and programmatic configuration
by Gaël Marziou 23 Aug '16

23 Aug '16

Hello, I have a spring boot application that uses logback-spring.xml to configure console or file appenders and logstash appender added programmatically because it requires dynamic properties from my application. It works well on app startup, but when I modify log level in logback-spring.xml the LoggerContext is reset and only the static configuration from logback-spring.xml is reloaded and so the logstash appender is no longer used. Behavior is the same with plain logback.xml So far, the only workaround I found is to add a LoggerContextListener that adds logstash appender on reset event. It works but I wonder whether this is the best way. I also thought of adding a listener to ReconfigureOnChangeTask but the addListener() method is package protected. I am using logback-classic 1.1.7 and spring-boot 1.4.0. Thanks, Gaël Marziou

1 0

Re: [logback-user] Custom Appender Configuration using generic Properties
by John Page 28 Jul '16

28 Jul '16

Ceki, Thanks for your reply. In your email you wrote: - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - "The second form would work just fine as long as "thisPropertyName" has a setter." - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - I realize each property could be configured by name, but the underlying library is deep and complex. It currently has 49 optional properties. It would require a significant amount of work to add the required setters to the Custom Appender. It would require even more work to maintain the Appender as the underlying library evolves and changes. By providing a "pass-through' Properties configuration, the custom appender will have a long life on Github with less maintenance required. Instead of using the appender documentation, developers can simply refer to the configuration guide provided by the underlying library. The Appender will simply pass the configured properties through to the underlying library. Cheers, John Page

1 0

Custom Appender Configuration using generic Properties
by John Page 28 Jul '16

28 Jul '16

Hi, I have developed a custom appender for logback and would like to configure it with a generic set of Properties that I can pass on to the underlying libraries. Rather than create a Getter and Setter for each property that the underlying library uses, I would like the configuration to read the names and values out of the logback configuration file. Instead of this: <configuration> Thanks, John Page

2 3

startListener ERROR when using Spring logback extension
by Leonid Kagan 28 Jul '16

28 Jul '16

After what looks like all appropriate configurations are performs to use logback with Spring web application a "SEVERE: Error listenerStart" is shown by Tomcat on the application start. Any ideas? The details of environment and configuration are below. Java 7 Tomcat 7 Spring 3.1.4 slf4j 1.7.5 logback-ext-spring 0.1.4 logback.xml: <configuration debug="true"> <appender name="appLogFile" class="ch.qos.logback.ext.spring.DelegatingLogbackAppender"/> <root level="debug"> <appender-ref ref="appLogFile" /> </root> </configuration> web.xml: .... <listener> <listener-class>ch.qos.logback.ext.spring.web.LogbackConfigListener</listener-class> </listener> <listener> <listener-class>org.springframework.web.context.ContextLoaderListener</listener-class> </listener> .... spring-app-config.xml: .... <bean class="ch.qos.logback.ext.spring.ApplicationContextHolder"/> <bean id="appLogFile" class="ch.qos.logback.core.FileAppender" init-method="start" destroy-method="stop"> <property name="context" value="#{ T(org.slf4j.LoggerFactory).getILoggerFactory() }"/> <property name="file" value="${catalina.home}/logs/${app.name }.log"/> <property name="encoder"> <bean class="ch.qos.logback.classic.encoder.PatternLayoutEncoder" init-method="start" destroy-method="stop"> <property name="context" value="#{ T(org.slf4j.LoggerFactory).getILoggerFactory() }"/> <property name="pattern" value="%d{HH:mm:ss.SSS} %-5level %logger{36} - %msg%n"/> </bean> </property> </bean> ....

1 0