March 2014 - logback-user - mailman3.qos.ch

Re: [logback-user] Logback suddenly stopped logging
by Andreas Dejung 19 Jun '14

19 Jun '14

I had the same problem and I think I know why J Solaris does interrupt IO blocked thread which then causes the OutputStreamAppender to catch the IOException in line 218 (version 0.9.24). I actually run version 0.9.18 but this part has not change so I guess it will behave the same way. If we look at http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=4385444 InterruptedIOException should not be required by platform specification (sol) And log4j https://issues.apache.org/bugzilla/show_bug.cgi?id=44157 InterruptedIOException ignored by log4j I think it should be solved the same why } catch (InterruptedIOException iioe){ //give the thread a changes to act on interruption and then carry on Thread.currentThread().interrupt(); } catch (IOException ioe) { // as soon as an exception occurs, move to non-started state // and add a single ErrorStatus to the SM. this.started = false; addStatus(new ErrorStatus("IO failure in appender", this, ioe)); } I could not find the jira entry mentioned in this thread therefore I write it here J BTY the jvm option -XX:-UseVMInterruptibleIO does prevent the interruption by solaris but that's only a workaround and not solving the problem ;) Cheers Andy

8 16

Re: [logback-user] Add header-lines to each log file
by Schoeftner, Thomas 20 May '14

20 May '14

Sorry to bump this topic again. Any ideas? Thanks, -Tom

3 2

How to view a log.txt file with LogBack-Beagle Eclipse plugin
by Gábor Hertelendy 26 Mar '14

26 Mar '14

Hello. I am a beginner with LogBack-beagle Eclipse plugin. So sorry for this question. Well, How can I view a log.txt file with Beagle Eclipse plugin? I am using Eclipse Kepler with PyDev plugin for a python application. This app has a little Logger class written in python and it writes its own log.txt file at runtime, I would like to view it with Beagle in Eclipse in two way: a, Like a tail view b, Like a post run log analysis Is it possible? Regards, Gabor Hertelendy

1 0

how to graceful shutdown logback with AsyncAppenders and without immediateFlush
by Gena Makhomed 21 Mar '14

21 Mar '14

Re: AsyncAppenderBase not flushing queue during JVM shutdown Michael Reinhold, I can propose better solution of described problem: we just need make two modes of work for logback: 1. normal mode, as it work all time after configuration finishing. 2. ready to shutdown mode, - fail safe mode, without messages lost. switching from "normal mode" to "ready to shutdown mode" do via JVM shutdown hook, - just one shutdown hook for logback. if logback turned from "normal mode" to "ready to shutdown mode", logback change own behavior in such way: 1. all appenders turn "immediateFlush = true", regardless of initial value in logback configuration, to prevent message lost during forthcoming JVM shutdown. 2. all AsyncAppenders turns into transparent and sync mode. if AsyncAppender work in this "transparent and sync mode", all behavior of app -> AsyncAppender -> RollingFileAppender -> file completly identical to behaviour of app -> RollingFileAppender -> file after switching from "normal mode" to "ready to shutdown mode", JVM shutdown hook finished work and now logback is ready to continue logging and also ready to forthcoming JVM shutdown. all other components of system still can use logback for logging during JVM/application shutdown process. here is only one unobvious nuance: how to transparently switch each logback AsyncAppender from async to sync mode without messages lost and without messages reordering in log. bit I am almost sure this is possible to do using java without perceptible performance degrade for AsyncAppender when it work in normal (async) mode. ================================================ IMHO, this is the most robust and most useful way to almost completly prevent any log messages lost during application and JVM shutdown. LoggerContext.stop() not prevent messages lost, so it should not be called before JVM shutdown. as I understand it mostly will be useful only for web applications, to be called in ServletContextListener.contextDestroyed() callback. Let me know, what you think about this new proposed solution. -- Best regards, Gena

2 13

Does logback really lose events during reconfiguration?
by Wojciech Kopras 19 Mar '14

19 Mar '14

I have read here < http://logging.apache.org/log4j/2.x/manual/index.html > that "Both Log4j 1.x and Logback will lose events while reconfiguring." Is it really true? Does it mean that some log entries, that happen during reconfiguration, may not be logged at all to the log file? -- Wojciech Kopras

1 0

Logback Rolling policy issue.
by Chandraprakash 12 Mar '14

12 Mar '14

Dear logback team, I am using logback-1.1.1 and slf4j-1.7.6. I am getting logs files generated in following format: 'someErrorLog_IS_UNDEFINED.log' which is undesired. My logback.xml is: <?xml version="1.0" encoding="UTF-8"?>  <configuration>  <property name="LOG_HOME" value="C:/Logs"/> <property name="infoLogName" value="someInfoLog"/> <property name="errorLogName" value="someErrorLog"/> <timestamp key="bySecond" datePattern="yyyyMMdd'T'HHmmss"/> <appender name="infofileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">  <file>C:/Logs/someInfoLog.log</file> <append>true</append> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">  <fileNamePattern>C:/Logs/someInfoLog.log.%d{'.'yyyy-MM-dd}</fileNamePattern>  <maxHistory>1</maxHistory> <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">  <maxFileSize>1MB</maxFileSize> </timeBasedFileNamingAndTriggeringPolicy> </rollingPolicy> <encoder>  <pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %-20.50logger{35} - %msg%n</pattern>  <immediateFlush>false</immediateFlush> <outputPatternAsHeader>true</outputPatternAsHeader> </encoder> </appender> <appender name="errorfileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">  <file>${LOG_HOME}/${someErrorLog}.log</file> <append>true</append> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">  <fileNamePattern>${someErrorLog}.%d{yyyy-MM-dd}.%i.log.zip</fileNamePattern>  <maxHistory>30</maxHistory> <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">  <maxFileSize>25MB</maxFileSize> </timeBasedFileNamingAndTriggeringPolicy> </rollingPolicy> <encoder>  <pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %-20.50logger{35} - %msg%n</pattern> <immediateFlush>true</immediateFlush> <outputPatternAsHeader>true</outputPatternAsHeader> </encoder> <filter class="ch.qos.logback.classic.filter.LevelFilter"> <level>ERROR</level> <onMatch>ACCEPT</onMatch> <onMismatch>DENY</onMismatch> </filter> </appender> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <append>true</append> <encoder> <pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %-20.50logger{35} - %msg%n</pattern> </encoder> </appender> <root level="TRACE" additivity="true"> <appender-ref ref="infofileAppender" /> <appender-ref ref="errorfileAppender"/> </root> </configuration> I am using glassfish 4 web profile server. The logs printed while stratup are: INFO: 15:11:25,188 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 15:11:25,189 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 15:11:25,190 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/workspaces/NetBeans/SomeProject7/build/web/WEB-INF/classes/logback.xml] 15:11:25,412 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set 15:11:25,449 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Using current interpretation time, i.e. now, as time reference. 15:11:25,451 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Adding property to the context with key="bySecond" and value="20140307T151125" to the LOCAL scope 15:11:25,451 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender] 15:11:25,464 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [infofileAppender] 15:11:25,754 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used 15:11:25,758 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern C:/Logs/someInfoLog.log.%d{'.'yyyy-MM-dd} for the active file 15:11:25,765 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b <mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b> - The date pattern is '.' from file name pattern 'C:/Logs/someInfoLog.log.%d{'.'yyyy-MM-dd}'. 15:11:25,765 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b <mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b> - Unknown periodicity. 15:11:25,765 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b <mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b> - Setting initial period to Fri Mar 07 15:11:25 IST 2014 15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@32:25 <mailto:ch.qos.logback.core.joran.spi.Interpreter@32:25> - RuntimeException in Action for tag [rollingPolicy] java.lang.IllegalStateException: Unknown periodicity type. at java.lang.IllegalStateException: Unknown periodicity type. at at ch.qos.logback.core.rolling.helper.RollingCalendar.getRelativeDate(RollingCalendar.java:234) at at ch.qos.logback.core.rolling.helper.RollingCalendar.getNextTriggeringDate(RollingCalendar.java:241) at at ch.qos.logback.core.rolling.helper.RollingCalendar.getNextTriggeringMillis(RollingCalendar.java:64) at at ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBase.computeNextCheck(TimeBasedFileNamingAndTriggeringPolicyBase.java:75) at at ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBase.start(TimeBasedFileNamingAndTriggeringPolicyBase.java:67) at at ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP.start(SizeAndTimeBasedFNATP.java:38) at at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.start(TimeBasedRollingPolicy.java:90) at at ch.qos.logback.core.joran.action.NestedComplexPropertyIA.end(NestedComplexPropertyIA.java:167) at at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317) at at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196) at at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182) at at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62) at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149) at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135) at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99) at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49) at at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75) at at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150) at at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85) at at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55) at at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129) at at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108) at at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302) at at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276) at at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288) at at com.edubond.web.security.AuthorizationListener.<clinit>(AuthorizationListener.java:30) at at java.lang.Class.forName0(Native Method) at at java.lang.Class.forName(Class.java:266) at at com.sun.faces.util.Util.loadClass(Util.java:301) at at com.sun.faces.config.processor.AbstractConfigProcessor.loadClass(AbstractConfigProcessor.java:376) at at com.sun.faces.config.processor.AbstractConfigProcessor.createInstance(AbstractConfigProcessor.java:278) at at com.sun.faces.config.processor.LifecycleConfigProcessor.addPhaseListeners(LifecycleConfigProcessor.java:132) at at com.sun.faces.config.processor.LifecycleConfigProcessor.process(LifecycleConfigProcessor.java:111) at at com.sun.faces.config.processor.AbstractConfigProcessor.invokeNext(AbstractConfigProcessor.java:152) at at com.sun.faces.config.processor.FactoryConfigProcessor.process(FactoryConfigProcessor.java:239) at at com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:435) at at com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:214) at at org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:5362) at at com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:743) at at org.apache.catalina.core.StandardContext.start(StandardContext.java:5898) at at com.sun.enterprise.web.WebModule.start(WebModule.java:691) at at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:1041) at at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:1024) at at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:747) at at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2278) at at com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1924) at at com.sun.enterprise.web.WebApplication.start(WebApplication.java:139) at at org.glassfish.internal.data.EngineRef.start(EngineRef.java:122) at at org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:291) at at org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:352) at at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:497) at at com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:219) at at org.glassfish.deployment.admin.DeployCommand.execute(DeployCommand.java:491) at at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:527) at at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:523) at at java.security.AccessController.doPrivileged(Native Method) at at javax.security.auth.Subject.doAs(Subject.java:356) at at com.sun.enterprise.v3.admin.CommandRunnerImpl$2.execute(CommandRunnerImpl.java:522) at at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:546) at at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:1423) at at com.sun.enterprise.v3.admin.CommandRunnerImpl.access$1500(CommandRunnerImpl.java:108) at at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1762) at at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1674) at at com.sun.enterprise.v3.admin.AdminAdapter.doCommand(AdminAdapter.java:534) at at com.sun.enterprise.v3.admin.AdminAdapter.onMissingResource(AdminAdapter.java:224) at at org.glassfish.grizzly.http.server.StaticHttpHandler.service(StaticHttpHandler.java:297) at at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:246) at at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191) at at org.glassfish.grizzly.http.server.HttpHandler.doHan INFO: dle(HttpHandler.java:168) at at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189) at at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) at at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288) at at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206) at at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136) at at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838) at at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) at at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564) at at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544) at at java.lang.Thread.run(Thread.java:722) 15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@34:18 <mailto:ch.qos.logback.core.joran.spi.Interpreter@34:18> - no applicable action for [encoder], current ElementPath is [[configuration][appender][encoder]] 15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@36:22 <mailto:ch.qos.logback.core.joran.spi.Interpreter@36:22> - no applicable action for [pattern], current ElementPath is [[configuration][appender][encoder][pattern]] 15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@38:29 <mailto:ch.qos.logback.core.joran.spi.Interpreter@38:29> - no applicable action for [immediateFlush], current ElementPath is [[configuration][appender][encoder][immediateFlush]] 15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@39:36 <mailto:ch.qos.logback.core.joran.spi.Interpreter@39:36> - no applicable action for [outputPatternAsHeader], current ElementPath is [[configuration][appender][encoder][outputPatternAsHeader]] 15:11:25,769 |-WARN in ch.qos.logback.core.rolling.RollingFileAppender[infofileAppender] - No TriggeringPolicy was set for the RollingFileAppender named infofileAppender 15:11:25,769 |-WARN in ch.qos.logback.core.rolling.RollingFileAppender[infofileAppender] - For more information, please visit http://logback.qos.ch/codes.html#rfa_no_tp 15:11:25,769 |-WARN in ch.qos.logback.core.joran.action.AppenderAction - The object at the of the stack is not the appender named [infofileAppender] pushed earlier. 15:11:25,769 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender] 15:11:25,769 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [errorfileAppender] 15:11:25,770 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use zip compression 15:11:25,770 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern someErrorLog_IS_UNDEFINED.%d{yyyy-MM-dd}.%i.log for the active file 15:11:25,771 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2 <mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2> - The date pattern is 'yyyy-MM-dd' from file name pattern 'someErrorLog_IS_UNDEFINED.%d{yyyy-MM-dd}.%i.log.zip'. 15:11:25,771 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2 <mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2> - Roll-over at midnight. 15:11:25,771 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2 <mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2> - Setting initial period to Mon Mar 03 15:52:40 IST 2014 15:11:25,775 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 15:11:25,901 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[errorfileAppender] - Active log file name: C:/Logs/someErrorLog_IS_UNDEFINED.log 15:11:25,901 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[errorfileAppender] - File property is set to [C:/Logs/someErrorLog_IS_UNDEFINED.log] 15:11:25,908 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 15:11:25,915 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT] 15:11:25,920 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@77:17 <mailto:ch.qos.logback.core.joran.spi.Interpreter@77:17> - no applicable action for [append], current ElementPath is [[configuration][appender][append]] 15:11:25,920 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 15:11:25,921 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to TRACE 15:11:25,921 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [infofileAppender] to Logger[ROOT] 15:11:25,923 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [errorfileAppender] to Logger[ROOT] 15:11:25,923 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 15:11:25,925 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@370ff5 <mailto:ch.qos.logback.classic.joran.JoranConfigurator@370ff5> - Registering current configuration as safe fallback point Please tell what is wrong in my configuration file? FileAppender is not working as expected. Regards, Chandra This e-mail and all material transmitted with it are for the use of the intended recipient(s) ONLY and contains confidential and/or privileged information. If you are not the intended recipient, please contact the sender by reply e-mail and destroy all copies and the original message. Any unauthorized review, use, disclosure, dissemination, forwarding, printing or copying of this email or any action taken pursuant to the contents of the present e-mail is strictly prohibited and is unlawful. The recipient acknowledges that Comviva Technologies Limited or its management or directors, are unable to exercise control or ensure the integrity over /of the contents of the information contained in e-mail. Any views expressed herein are those of the individual sender only and no binding nature of the contents shall be implied or assumed unless the sender does so expressly with due authority of Comviva Technologies Limited. E-mail and any contents transmitted with it are prone to viruses and related defects despite all efforts to avoid such by Comviva Technologies Limited.

2 6

ServiceLoader-like initialization for logback
by Adam Gent 11 Mar '14

11 Mar '14

For logback I have always wanted to have better control over the automatic initialization. That is I wish the automatic init followed something more similar to the ServiceLoader in Java: http://docs.oracle.com/javase/6/docs/api/java/util/ServiceLoader.html That is a resource should be used to point to what code should do the initialization instead of having to use system properties or hijacking the already loaded config. Basically I want the auto configuration to load some Java code before it does the default which according to the manual is first load logback.groovy, then logback.xml, etc. I original asked this question on StackOverflow but after reading the documentation I think its a missing feature so I decided w/ the mailing list (apologies for crossposting). http://stackoverflow.com/questions/22335441/configure-logback-xml-to-defer-… Cheers, -Adam -- CTO SnapHop (snaphop.com) (twitter) @agentgt (linkedin) http://www.linkedin.com/in/agentgt (cell) 781-883-5182

1 0

AsyncAppenderBase not flushing queue during JVM shutdown
by Michael Reinhold 08 Mar '14

08 Mar '14

Hi Ceki, I am currently using the AsyncAppender in combination with the LogglyAppender from the Logback extensions project. While working on a number of aspects of my application, I found that I was not consistently getting all of the log messages that I expected. In particular, when the application shuts down immediately (or very shortly) after a burst of logging activity, the tail of those log events is often not present in Loggly. From a number of tests, this issue is not restricted to use with the LogglyAppender, but is simply more evident because of the latency involved. Looking through the source code for the AsyncAppenderBase, I saw the following: You create the Async sender thread as a Daemon thread addInfo("Setting discardingThreshold to " + discardingThreshold); worker.setDaemon(true); worker.setName("AsyncAppender-Worker-" + worker.getName()); // make sure this instance is marked as "started" before staring the worker Thread super.start(); worker.start(); In the sender thread, if you determine that the parent thread has stopped or the async sender thread has been interrupted, you allow the worker thread to flush remaining log events in the queue. while (parent.isStarted()) { try { E e = parent.blockingQueue.take(); aai.appendLoopOnAppenders(e); } catch (InterruptedException ie) { break; } } addInfo("Worker thread will flush remaining events before exiting. "); for (E e : parent.blockingQueue) { aai.appendLoopOnAppenders(e); } aai.detachAndStopAllAppenders(); >From what I can tell, during JVM shutdown (for a standalone SE instance, the same is probably not true for EE instances with application servers) daemon threads may be terminated without allowing the the AsyncAppenderBase to escape the while loop and proceed onto the queue flush for loop. >From Brian Goetz in Java Concurrency in Practice: "When a thread exits, the JVM performs an inventory of running threads, and if the only threads that are left are daemon threads, it initiates an orderly shutdown. When the JVM halts, any remaining daemon threads are abandoned finally blocks are not executed, stacks are not unwound the JVM just exits. Daemon threads should be used sparingly few processing activities can be safely abandoned at any time with no cleanup. In particular, it is dangerous to use daemon threads for tasks that might perform any sort of I/O. Daemon threads are best saved for "housekeeping" tasks, such as a background thread that periodically removes expired entries from an in-memory cache." To test this, I inserted a break point in the AsyncAppenderBase at the call to addInfo and ran a variety of different scenarios. At no point in time was I able to get the breakpoint to stop at the addInfo line. I don't think there are any clear cut solutions to this. Making the worker thread a user thread instead of daemon thread has its own implications, particularly that if all other user threads have exited the async threads would keep the JVM instance alive (unless System.exit has been called, in which case I believe that you will still have lost log events even if the async processing thread is not a daemon). It might be possible to create a shutdown hook that does the queue flushing for the async worker - though you may need to consider the possibility of other shutdown hooks wanting to log events as well. I'm currently mocking up a version of the AsyncAppenderBase and AsyncAppender that installs a shutdown hook as described previously. I think a "queue idle time" configuration might be the best way to handle other shutdown hooks adding log events (aka - after processing whatever was in the queue, if no new events are added within *x* ms then the shutdown hook can assume nothing else will be adding log events and can exit). An alternative might be to have the shutdown hook query the ThreadMXBean API to determine if other shutdown hooks are still executing and possibly adding log events (though the threads that are expected to be running during shutdown may be not only application specific but also JVM implementation specific... I'm not sure). Let me know what you think. I'll let you know if I feel that my mockup may be viable... Regards, Mike Reinhold

4 12

Logback and WebLogic Server 11gR1 10.3.4
by Davide Castellano 04 Mar '14

04 Mar '14

TO THE MODERATOR: I'm sorry if I'm submitting for the second time the same messge, but the previous one was really bad formatted, hope this one would be readable. After many attempts I can't print the log to a file. - Result on STDOUT: <3-mar-2014 13.10.53 CET> <Notice> <WebLogicServer> <BEA-000360> <Server started in RUNNING mode> 0 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN it.foo - I love programming. 0 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] ERROR it.foo - I am programming. The file MyLog.log is still not written. - This is what I've done: **************************** ListMan.ear | -\META-INF | - weblogic-application.xml - logback.xml - ConsoleAmministr.war | - \WEB-INF | weblogic.xml logback.xml | - \lib | - logback-classic-1.1.1.jar - logback-core-1.1.1.jar - slf4j-api-1.7.6.jar - \classes | logback.xml - \it | - foo.java - \resource | - logback.xml *********************************************************** logback.xml: <?xml version="1.0" encoding="UTF-8"?> <configuration> <appender name="FILE" class="ch.qos.logback.core.FileAppender"> <file>MyLog.log</file> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> <logger name="it" level="TRACE"/> <root level="debug"> <appender-ref ref="FILE" /> </root> </configuration> *********************************************************** foo.java: ... import org.slf4j.Logger; import org.slf4j.LoggerFactory; ... static final Logger LOG = LoggerFactory.getLogger(foo.class); ... LOG.info("I am fine."); LOG.warn("I love programming."); LOG.error("I am programming."); ... *********************************************************** weblogic.xml: <?xml version="1.0" encoding="UTF-8"?> <weblogic-web-app xmlns="http://xmlns.oracle.com/weblogic/weblogic-web-app" xmlns:j2ee="http://java.sun.com/xml/ns/j2ee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/ejb-jar_3_0.xsd http://xmlns.oracle.com/weblogic/weblogic-web-app http://xmlns.oracle.com/weblogic/weblogic-web-app/1.2/weblogic-web-app.xsd"> <jsp-descriptor> <keepgenerated>true</keepgenerated> </jsp-descriptor> <context-root>/ConsoleAmministr</context-root> <weblogic-version>10.3.5</weblogic-version> <container-descriptor> <prefer-application-packages> <package-name>org.slf4j</package-name> </prefer-application-packages> </container-descriptor> </weblogic-web-app> *********************************************************** weblogic-application.xml: <?xml version="1.0" encoding="UTF-8"?> <weblogic-application xmlns="http://www.bea.com/ns/weblogic/90"> <prefer-application-packages> <package-name>org.slf4j.*</package-name> <package-name>antlr.*</package-name> </prefer-application-packages> <prefer-application-resources> <resource-name>org/slf4j/impl/StaticLoggerBinder.class</resource-name> </prefer-application-resources> </weblogic-application> *********************************************************** Thanks in advance for your help, Dave

1 0

Logback 1.1.1 and WebLogic Server 11gR1 10.3.4
by Davide Castellano 04 Mar '14

04 Mar '14

After many attempts I can't print the log to a file. - Result on STDOUT: <3-mar-2014 13.10.53 CET> <Notice> <WebLogicServer> <BEA-000360> <Server started in RUNNING mode> 0 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] WARN it.isp.swa.ProfiloSWA - I love programming. 0 [[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'] ERROR it.isp.swa.ProfiloSWA - I am programming. The file MyLog.log is still not written. - This is what I've done: ****************************ListMan.ear | -\META-INF | - weblogic-application.xml - logback.xml - ConsoleAmministr.war | - \WEB-INF | weblogic.xml logback.xml | - \lib | - logback-classic-1.1.1.jar - logback-core-1.1.1.jar - slf4j-api-1.7.6.jar - \classes | logback.xml - \it | - foo.java - \resource | - logback.xml***********************************************************logback.xml: <?xml version="1.0" encoding="UTF-8"?><configuration> <appender name="FILE" class="ch.qos.logback.core.FileAppender"><file>MyLog.log</file> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> <logger name="it" level="TRACE"/> <root level="debug"> <appender-ref ref="FILE" /> </root></configuration>***********************************************************foo.java:...import org.slf4j.Logger;import org.slf4j.LoggerFactory;... static final Logger LOG = LoggerFactory.getLogger(foo.class);... LOG.info("I am fine."); LOG.warn("I love programming."); LOG.error("I am programming.");...***********************************************************weblogic.xml: <?xml version="1.0" encoding="UTF-8"?><weblogic-web-app xmlns="http://xmlns.oracle.com/weblogic/weblogic-web-app" xmlns:j2ee="http://java.sun.com/xml/ns/j2ee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/ejb-jar_3_0.xsd http://xmlns.oracle.com/weblogic/weblogic-web-app http://xmlns.oracle.com/weblogic/weblogic-web-app/1.2/weblogic-web-app.xsd"> <jsp-descriptor> <keepgenerated>true</keepgenerated> </jsp-descriptor> <context-root>/ConsoleAmministr</context-root> <weblogic-version>10.3.5</weblogic-version> <container-descriptor> <prefer-application-packages> <package-name>org.slf4j</package-name> </prefer-application-packages> </container-descriptor></weblogic-web-app>***********************************************************weblogic-application.xml: <?xml version="1.0" encoding="UTF-8"?><weblogic-application xmlns="http://www.bea.com/ns/weblogic/90"> <prefer-application-packages> <package-name>org.slf4j.*</package-name> <package-name>antlr.*</package-name> </prefer-application-packages> <prefer-application-resources> <resource-name>org/slf4j/impl/StaticLoggerBinder.class</resource-name> </prefer-application-resources> </weblogic-application>***********************************************************

1 0