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

How to get rollingfileappender to roll over based on log size
by Jeremy Kane 28 Jul '14

28 Jul '14

I've been trying to get the rollinglogfileappender to roll-over at a certain file size, but I've had no luck. I can get it to roll over at midnight each night, but I still would prefer to either combine them or have it just be file-size limited. My config is such: // Rolling Log Appender String fileDirectory = KanetikApplication.getFileDirectory(context); RollingFileAppender<ILoggingEvent> rollingFileAppender = new RollingFileAppender<ILoggingEvent>(); rollingFileAppender.setContext(loggerContext); rollingFileAppender.setAppend(true); rollingFileAppender.setFile(fileDirectory + "/log.txt"); TimeBasedRollingPolicy<ILoggingEvent> rollingPolicy = new TimeBasedRollingPolicy<ILoggingEvent>(); rollingPolicy.setMaxHistory(2); rollingPolicy.setFileNamePattern(fileDirectory + "/log.%d.txt"); rollingPolicy.setParent(rollingFileAppender); rollingPolicy.setContext(loggerContext); rollingPolicy.start(); rollingFileAppender.setRollingPolicy(rollingPolicy); PatternLayoutEncoder fileEncoder = new PatternLayoutEncoder(); fileEncoder.setContext(loggerContext); fileEncoder.setPattern("%d{h:mm:ss} %level - %msg%n"); fileEncoder.start(); rollingFileAppender.setEncoder(fileEncoder); rollingFileAppender.start(); // LogCat Appender PatternLayoutEncoder logcatEncoder = new PatternLayoutEncoder(); logcatEncoder.setContext(loggerContext); logcatEncoder.setPattern("%msg%n"); logcatEncoder.start(); PatternLayoutEncoder tagEncode = new PatternLayoutEncoder(); tagEncode.setContext(loggerContext); tagEncode.setPattern(tag); tagEncode.start(); LogcatAppender logcatAppender = new LogcatAppender(); logcatAppender.setContext(loggerContext); logcatAppender.setEncoder(logcatEncoder); logcatAppender.setTagEncoder(tagEncode); logcatAppender.start(); // add the newly created appenders to the root logger; // qualify Logger to disambiguate from org.slf4j.Logger ch.qos.logback.classic.Logger root = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); root.setLevel(level); root.addAppender(rollingFileAppender); root.addAppender(logcatAppender); Can anyone tell me why it's not working? Thanks! J

3 3

IllegalStateException caused by logback 1.1.2
by Gena Makhomed 19 Jun '14

19 Jun '14

Hello, All! to prevent "AsynAppender thread leak" as described in http://jira.qos.ch/browse/LOGBACK-867 I use recommended in documentation http://logback.qos.ch/manual/appenders.html#AsyncAppender approach: public class LogbackShutdownHook implements ServletContextListener { // ... @Override public void contextDestroyed(ServletContextEvent sce) { logger.info("******* stop logger *******"); LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); loggerContext.stop(); } } web.xml: <listener> <listener-class>com.pb.ivrcgate.util.servlet.LogbackShutdownHook</listener-class> </listener> but this causes IllegalStateException in tomcat log: May 28, 2014 3:36:36 PM org.apache.catalina.loader.WebappClassLoader loadClass INFO: Illegal access: this web application instance has been stopped already. Could not load ch.qos.logback.core.status.WarnStatus. The eventual following java.lang.IllegalStateException at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1612) at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1571) at ch.qos.logback.classic.LoggerContext.noAppenderDefinedWarning(LoggerContext.java:175) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:267) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:442) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396) at ch.qos.logback.classic.Logger.log(Logger.java:788) at org.apache.commons.logging.impl.SLF4JLocationAwareLog.debug(SLF4JLocationAwareLog.java:133) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.shutdown(PoolingHttpClientConnectionManager.java:345) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.finalize(PoolingHttpClientConnectionManager.java:168) at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method) at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:101) at java.lang.ref.Finalizer.access$100(Finalizer.java:32) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:190) in my webapp org.apache.httpcomponents:httpclient:4.3.3 used. sourse PoolingHttpClientConnectionManager.java line #345 is: this.log.debug("Connection manager is shutting down"); ============================================================== how to prevent IllegalStateException in tomcat log? I am doing something wrong, or this is bug in logback code? 1) may be method shutdown() should be added to logback, and after shutdown - all events and messages should be silently ignored? 2) or better add to logback new "fallback mode" - in this mode all async appenders should be stopped and all buffers disabled, all events written to logs and flushed immediately, without delays. "fallback mode" can be used in contextDestroyed() methods or in low memory conditions, before near OutOfMemoryError to prevent any logging events lost in buffers and queues. 3) ................................... something else? -- Best regards, Gena

2 1

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

logback skipping log files on AWS EC2
by Bob Sandiford 19 Jun '14

19 Jun '14

I'm using logback for logging from an app deployed in Tomcat, with a fairly simple setup (see code fragments). We use a RollingFileAppender, with TimeBasedRollingPolicy, set for daily rollover. When running locally, everything appears to be fine. When running in AWS in an EC2 instance, I'm seeing that some log files are missing. I wrote a really simple app that does nothing but log once per second with a counter, and then a logback config that rolls every minute. For this particular test, we're seeing every third log file is missing. So, for example, we'll get: -rw-r--r-- 1 tomcat tomcat 891 May 13 18:46 logtest_tomcat.2014-05-13_1845.0.log.gz -rw-r--r-- 1 tomcat tomcat 499 May 13 18:47 logtest_tomcat.2014-05-13_1846.0.log.gz -rw-r--r-- 1 tomcat tomcat 541 May 13 18:49 logtest_tomcat.2014-05-13_1848.0.log.gz -rw-r--r-- 1 tomcat tomcat 519 May 13 18:50 logtest_tomcat.2014-05-13_1849.0.log.gz -rw-r--r-- 1 tomcat tomcat 532 May 13 18:52 logtest_tomcat.2014-05-13_1851.0.log.gz -rw-r--r-- 1 tomcat tomcat 510 May 13 18:53 logtest_tomcat.2014-05-13_1852.0.log.gz -rw-r--r-- 1 tomcat tomcat 536 May 13 18:55 logtest_tomcat.2014-05-13_1854.0.log.gz -rw-r--r-- 1 tomcat tomcat 1226 May 13 18:56 logtest_tomcat.2014-05-13_1855.0.log.gz -rw-r--r-- 1 tomcat tomcat 531 May 13 18:58 logtest_tomcat.2014-05-13_1857.0.log.gz -rw-r--r-- 1 tomcat tomcat 496 May 13 18:59 logtest_tomcat.2014-05-13_1858.0.log.gz -rw-r--r-- 1 tomcat tomcat 1244 May 13 19:01 logtest_tomcat.2014-05-13_1900.0.log.gz -rw-r--r-- 1 tomcat tomcat 496 May 13 19:02 logtest_tomcat.2014-05-13_1901.0.log.gz -rw-r--r-- 1 tomcat tomcat 514 May 13 19:04 logtest_tomcat.2014-05-13_1903.0.log.gz -rw-r--r-- 1 tomcat tomcat 500 May 13 19:05 logtest_tomcat.2014-05-13_1904.0.log.gz -rw-r--r-- 1 tomcat tomcat 522 May 13 19:07 logtest_tomcat.2014-05-13_1906.0.log.gz The file format is yyyy-mm-dd_HHmm - so you can see that 1847, 1850, 1853, 1856, 1859, 1902, 1905 are all missing. I've checked the contents - the sequential numbering on the log statements jumps by 60 for the missing logs - so it's not that multiple minutes are being collapsed into a single rolled over log. We also thought it might be due to our Splunk forwarder - we ran the test both with and without the Splunk forwarder running, and got the same results - every third log file is missing. Here's the logback appender for this test: <appender name="daily" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>${bc.logs.home}/logtest_tomcat.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">  <fileNamePattern>${bc.logs.home}/logtest_tomcat.%d{yyyy-MM-dd_HHmm}.%i.log.gz</fileNamePattern> <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">  <maxFileSize>250MB</maxFileSize> </timeBasedFileNamingAndTriggeringPolicy> <maxHistory>60</maxHistory> </rollingPolicy> <append>true</append> <encoder> <pattern>%d{"yyyy-MM-dd HH:mm:ss,SSS z", UTC} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> And here's my little driver class (the 'BCLog' is a simple wrapper around slf4j logging, instantiated by Logger log = LoggerFactory.getLogger(clazz); ) package com.sirsidynix.logtest.biz.svc.impl; import com.sirsidynix.bccommon.util.BCLog; import com.sirsidynix.bccommon.util.BCLogFactory; import org.springframework.beans.factory.DisposableBean; import org.springframework.beans.factory.InitializingBean; public class JustLogIt implements InitializingBean, DisposableBean { private static final BCLog LOG = BCLogFactory.getLog(JustLogIt.class); private Thread thread; @Override public void afterPropertiesSet() throws Exception { LOG.info("Firing up JustLogIt thread"); thread = new Thread(){ @Override public void run() { long iteration = 0; while (true) { try { Thread.sleep(1000); iteration++; LOG.info("Logging Iteration " + iteration); } catch (InterruptedException e) { LOG.info("LogIt thread sleep interrupted!!!"); } } } }; thread.start(); } @Override public void destroy() throws Exception { LOG.info("Shutting down JustLogIt thread"); thread.interrupt(); } } Any ideas? Thanks! Bob Sandiford | Principal Engineer | SirsiDynix P: 800.288.8020 X6943 | Bob.Sandiford(a)sirsidynix.com<mailto:Bob.Sandiford@sirsidynix.com> www.sirsidynix.com<http://www.sirsidynix.com/> Join the conversation: Like us on Facebook!<http://www.facebook.com/SirsiDynix> Follow us on Twitter!<http://twitter.com/SirsiDynix>

2 2

multiple servlet with differents files in glassfish
by Pablo Martínez Campo 27 May '14

27 May '14

I am trying to deploy 2 servlets in glassfish with log4f library. I have no problems in tomcat. Each servlet writes in its own file but in tomcat, I found this guide https://blogs.oracle.com/naman/entry/configure_log4j_for_use_in to configure and support log4f library. I got the first servlet working with it. And it writes logs in its log file. But whenever I deploy the secod servlet, I don't see its logs. The first one keeps writing in its own file but the second one not. I modify the logback.xml file included in config folder to include both files and all packages but it seems to ignore it. This is my logback.xml file: <?xml version="1.0" encoding="UTF-8"?> <configuration> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">  <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{5} - %msg%n</pattern> </encoder> </appender> <logger name="com.lordofthejars.foo" level="INFO" additivity="false"> <appender-ref ref="STDOUT" /> </logger> <appender name="SERVER-FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> 0 <fileNamePattern>/root/glassfish4/glassfish/domains/domain1/logs/serverregister-%d{yyyy-MM-dd}.%i.log</fileNamePattern>  <maxHistory>7</maxHistory> <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP"> <MaxFileSize>512MB</MaxFileSize> </TimeBasedFileNamingAndTriggeringPolicy> </rollingPolicy> <append>true</append> <encoder> <pattern>%d{dd-MM-yyyy HH:mm:ss.SSS} [%p] %logger{5}:%L - %msg%n</pattern> </encoder> </appender> <appender name="REGMAN-FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">   <fileNamePattern>/root/glassfish4/glassfish/domains/domain1/logs/registermanager-%d{yyyy-MM-dd}.%i.log</fileNamePattern>  <maxHistory>7</maxHistory> <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP"> <MaxFileSize>512MB</MaxFileSize> </TimeBasedFileNamingAndTriggeringPolicy> </rollingPolicy> <append>true</append> <encoder> <pattern>%d{dd-MM-yyyy HH:mm:ss.SSS} [%p] %logger{5}:%L - %msg%n</pattern> </encoder> </appender> <logger name="com.eu.iotapi.handlers.AuthenticationGatewayHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.handlers.AuthenticationHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.handlers.DeviceValidationHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.handlers.EventValidationHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.handlers.GatewayValidationHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.handlers.ObservationValidationHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.resources.PublicationsResource" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.resources.RegisterDeviceOnBackground" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.resources.RegisterGatewayOnBackground" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.resources.RegistrationResource" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.resources.SubmitEventOnBackground" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.resources.SubmitObservationOnBackground" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.uns.device.RegisterDeviceHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.uns.events.SubmitEventsHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.uns.device.RegisterGatewayHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.uns.observations.SubmitObservationsHandler" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.iotapi.resources.DeviceTranslator" level="DEBUG" additivity="false"> <appender-ref ref="SERVER-FILE"/> </logger> <logger name="com.eu.registermanager.eventbroker.device.registration.DeviceRegistrationHandler" level="DEBUG" additivity="false"> <appender-ref ref="REGMAN-FILE"/> </logger> <logger name="com.eu.registermanager.eventbroker.gateway.GatewayRegistrationHandler" level="DEBUG" additivity="false"> <appender-ref ref="REGMAN-FILE"/> </logger> <logger name="com.eu.registermanager.handlers.AuthenticationGatewayHandler" level="DEBUG" additivity="false"> <appender-ref ref="REGMAN-FILE"/> </logger> <logger name="com.eu.registermanager.handlers.AuthenticationHandler" level="DEBUG" additivity="false"> <appender-ref ref="REGMAN-FILE"/> </logger> <logger name="com.eu.registermanager.resources.RegisterDeviceOnEventBrokerOnBackground" level="DEBUG" additivity="false"> <appender-ref ref="REGMAN-FILE"/> </logger> <logger name="com.eu.registermanager.resources.RegisterGatewayOnEventBrokerOnBackground" level="DEBUG" additivity="false"> <appender-ref ref="REGMAN-FILE"/> </logger> <logger name="com.eu.registermanager.resources.RegisterResource" level="DEBUG" additivity="false"> <appender-ref ref="REGMAN-FILE"/> </logger> <root level="INFO"> <appender-ref ref="STDOUT" /> </root> </configuration>

1 0

jcl-over-slf4j problem
by lee json 26 May '14

26 May '14

I understand this might not logback's issue, but I would like to collect more information so hope to fix my problem. Basically there is no problem to execute unit tests if I removed all logback related dependency. I am just wondering what inside jcl-over-slf4j may collide against dependencies in my project. I notice that when I add jcl-over-slf4j as dependency <dependency> <groupId>org.slf4j</groupId> <artifactId>jcl-over-slf4j</artifactId> <version>1.7.5</version> </dependency> this leads to my test case not being executed with maven result printed "no tests were executed!". My scala test version is 2.10 <dependency> <groupId>org.scalatest</groupId> <artifactId>scalatest_2.10</artifactId> <version>2.0</version> <scope>test</scope> </dependency> and junit version is 4.8.1 <dependency> <groupId>junit</groupId> <artifactId>junit</artifactId> <version>4.8.1</version> </dependency> If I comment out jcl-over-slf4j, maven reports "there are tests failure" Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.6:test (default-test) ...: There are test failures Please refer to.../target/surefire-reports for the individual test results. But surefire-reports folder actually is not created $ ls target/surefire-reports ls: cannot access target/surefire-reports: No such file or directory Environment I use Maven version is 3.0.5 Java version 1.6.x I appreciate any suggestions. Thanks

2 2

Switch logging to different files at runtime
by lee json 23 May '14

23 May '14

I test to run a sample logging message to a file. But I am wondering how can I switch logging to different files at runtime? For example, initially the message is logged to <log_dir>/<file_a>.log. Later on I would like the application to log message to <log_dir>/<file_b>.log. Is it doable with logback lib? I want to log message to logs/<parent_key_id>/<key_id>...log. Is RollingPolicy configured to start up once? How can I change logging to another log file such as logs/<parent_key_id1>/<key_id1>...log when certain condition is met? Thanks The current setting: logback.xml <?xml version="1.0" encoding="UTF-8"?> <configuration scan="false" debug="false"> <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <rollingPolicy class="sample.logging.MyRollingPolicy"> <FileNamePattern>%keyId_%d.log.gz</FileNamePattern> <MaxHistory>60</MaxHistory> </rollingPolicy> <layout class="ch.qos.logback.classic.PatternLayout">  <Pattern>[%4p] [%d{ISO8601}] [%t] %c{1}: %m%n</Pattern> </layout> </appender> <root level="INFO"> <appender-ref ref="FILE"/> </root> </configuration> MyRolling.scala package sample.logging import java.io.File import ch.qos.logback.core.rolling.TimeBasedRollingPolicy; class MyRollingPolicy[E] extends TimeBasedRollingPolicy[E] { override def setFileNamePattern(fnp: String) { try{ println("fnp passed in: "+fnp) val fnp1 = fnp.replace("%keyId", "k_1_3") println("[after replaced] fnp1 now is "+fnp1) val f = new File("logs/" + "parent_key_id"); // Logback will create any necessary parent paths. super.setFileNamePattern(f.getAbsolutePath() + "/" + fnp1); } catch { case e: Exception => { println("something go wrong..."+e) throw new RuntimeException(e); } } } }

2 2

FW: Antwort: Deadlock in case of console appender and system.out/err captured
by Dancewicz Grzegorz 22 May '14

22 May '14

Hi, Last days I had to update from logback 0.9.15 to the 1.1.2. Since this update the multithreaded test I have, dies in a deadlock. This test simply tries to simultaneously write to System.err and System.out in different threads. I use the logback under SLF4J(1.7.7) logging facade and additionally I also redirect the System.out and System.err into the the logback via SLF4J. For this purpose I have written my own OutputStream which I set as System.out and System.err (different instance for each). This stream writes forward using the ILogger (logback). Additionally the logback is configured in a way, that (among others) it has a ConsoleAppender from logback.core package. Finally, this results in the ConsoleTarget class using System.out/System.err to write to the console and here the deadlock happens. Does anyone had similar case or problems? Something must have changed in the locking system of Logback as the multithreaded test case passes with version 0.9.15 of Logback. I also tried to replace my own capturing stream written for System.out and System.err with the stuff from sysout-ver-slf4j from lidalia (project information link: http://projects.lidalia.org.uk/sysout-over-slf4j/project-summary.html) but the dealock behavior was exactly the same. I will appreciate any hints and help. Below there is a thread dump from jvisualvm and also the logback configuration used + test snippet: Found one Java-level deadlock: ============================= "Thread-226": waiting to lock monitor 0x19ebc774 (object 0x04621280, a java.io.PrintStream), which is held by "Thread-28" "Thread-28": waiting to lock monitor 0x188392e4 (object 0x0461afe8, a java.io.PrintStream), which is held by "Thread-27" "Thread-27": waiting for ownable synchronizer 0x0ab25c88, (a java.util.concurrent.locks.ReentrantLock$FairSync), which is held by "Thread-28" Java stack information for the threads listed above: =================================================== "Thread-226": at java.io.PrintStream.write(PrintStream.java:523) - waiting to lock <0x04621280> (a java.io.PrintStream) at java.io.PrintStream.print(PrintStream.java:669) at mhcc.cci.logging.SystemOutErrTest$4.run(SystemOutErrTest.java:349) at java.lang.Thread.run(Thread.java:744) "Thread-28": at java.io.PrintStream.write(PrintStream.java:478) - waiting to lock <0x0461afe8> (a java.io.PrintStream) at java.io.FilterOutputStream.write(FilterOutputStream.java:97) at ch.qos.logback.core.joran.spi.ConsoleTarget$1.write(ConsoleTarget.java:36) at ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(LayoutWrappingEncoder.java:135) at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:194) at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:219) at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:273) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:260) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:442) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396) at ch.qos.logback.classic.Logger.error(Logger.java:563) at mhcc.cci.logging.internal.Slf4JLoggerWrapper.error(Slf4JLoggerWrapper.java:573) at mhcc.cci.logging.internal.LoggerOutputStream.writeToLog(LoggerOutputStream.java:223) at mhcc.cci.logging.internal.LoggerOutputStream.handleLogFragment(LoggerOutputStream.java:170) at mhcc.cci.logging.internal.LoggerOutputStream.flush(LoggerOutputStream.java:150) at java.io.PrintStream.write(PrintStream.java:482) - locked <0x04621280> (a java.io.PrintStream) at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221) at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291) at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104) - locked <0x04621400> (a java.io.OutputStreamWriter) at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185) at java.io.PrintStream.newLine(PrintStream.java:546) - locked <0x04621280> (a java.io.PrintStream) at java.io.PrintStream.println(PrintStream.java:807) - locked <0x04621280> (a java.io.PrintStream) at mhcc.cci.logging.SystemOutErrTest$4.run(SystemOutErrTest.java:353) at java.lang.Thread.run(Thread.java:744) "Thread-27": at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0ab25c88> (a java.util.concurrent.locks.ReentrantLock$FairSync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197) at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:229) at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290) at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:217) at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:273) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:260) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:442) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396) at ch.qos.logback.classic.Logger.info(Logger.java:620) at mhcc.cci.logging.internal.Slf4JLoggerWrapper.info(Slf4JLoggerWrapper.java:333) at mhcc.cci.logging.internal.LoggerOutputStream.writeToLog(LoggerOutputStream.java:213) at mhcc.cci.logging.internal.LoggerOutputStream.handleLogFragment(LoggerOutputStream.java:170) at mhcc.cci.logging.internal.LoggerOutputStream.flush(LoggerOutputStream.java:150) at java.io.PrintStream.write(PrintStream.java:482) - locked <0x0461afe8> (a java.io.PrintStream) at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221) at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291) at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104) - locked <0x0461b168> (a java.io.OutputStreamWriter) at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185) at java.io.PrintStream.newLine(PrintStream.java:546) - locked <0x0461afe8> (a java.io.PrintStream) at java.io.PrintStream.println(PrintStream.java:807) - locked <0x0461afe8> (a java.io.PrintStream) at mhcc.cci.logging.SystemOutErrTest$3.run(SystemOutErrTest.java:336) at java.lang.Thread.run(Thread.java:744) Found 1 deadlock. ================================ Logback configuration: <?xml version="1.0" encoding="UTF-8" ?>  <configuration scan="true" scanPeriod="120 seconds"> <jmxConfigurator /> <conversionRule conversionWord="bundle" converterClass="mhcc.cci.logging.internal.BundleMarkerConverter" /> <conversionRule conversionWord="category" converterClass="mhcc.cci.logging.internal.CategoryMarkerConverter" />  <appender name="TEST" class="mhcc.cci.logging.internal.test.LogbackAppenderQueue"/> <appender name="STDOUT" class="ch.qos.logback.core.MHCCConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <pattern>%date{HH:mm:ss.SSS} %-5level [%-15.15thread] %-25.25logger{25} [%mdc] %msg%n</pattern> </layout> </appender> <appender name="LOGFILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <File>${user.home}/dcvl/logs/component.log</File> <Append>true</Append> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{ISO8601}\t*\t%level\t%category\t[%-29.29thread]\t%26.26bundle/%-36.36logger{36}\t[%mdc]\t*\t%msg%n </Pattern> </layout> <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy"> <FileNamePattern>${user.home}/dcvl/logs/component.%i.log.zip</FileNamePattern> <MinIndex>0</MinIndex> <MaxIndex>10</MaxIndex> </rollingPolicy> <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy"> <MaxFileSize>50MB</MaxFileSize> </triggeringPolicy> </appender> <appender name="AUDITLOGFILE" class="ch.qos.logback.core.FileAppender"> <Filter class="mhcc.cci.logging.internal.CategoryFilter"> <category>AUDIT</category> </Filter> <File>${user.home}/dcvl/logs/audit.log</File> <Append>true</Append> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{ISO8601}\t*\t%level\t%category\t[%-29.29thread]\t%26.26bundle/%-36.36logger{36}\t[%mdc]\t*\t%msg%n</Pattern> </layout> </appender>  <logger name="TEST" level="TRACE"> <appender-ref ref="TEST" /> </logger> <logger name="mhcc.cci.configurator.dsl.modelprovider.internal.RuntimeMHCfgURIConverter" level="INFO" /> <logger name="mhcc.cci.logging.internal.Slf4jBundleEventLogger" level="INFO" /> <logger name="org.springframework" level="WARN" /> <logger name="org.springframework.osgi" level="WARN" /> <root level="debug"> <appender-ref ref="STDOUT" /> <appender-ref ref="LOGFILE" /> <appender-ref ref="AUDITLOGFILE" /> </root> </configuration> ================================= Test snippet: final int NUM_TEST_THREADS = 2 * 100; // must be en even number final ConcurrentLinkedQueue<Exception> exceptions = new ConcurrentLinkedQueue<Exception>(); final Runnable useOut = new Runnable() { @Override public void run() { try { System.out.print( "dummy text, " ); Thread.yield(); System.out.println( "rest of text" ); } catch ( Exception e ) { exceptions.add( e ); } } }; final Runnable useErr = new Runnable() { @Override public void run() { try { System.err.print( "dummy text, " ); Thread.yield(); System.err.println( "rest of text" ); } catch ( Exception e ) { exceptions.add( e ); } } }; Thread[] testThreads = new Thread[ NUM_TEST_THREADS ]; for ( int i = 0; i < NUM_TEST_THREADS; i += 2 ) { testThreads[ i ] = new Thread( useOut ); testThreads[ i + 1 ] = new Thread( useErr ); } // all threads run in parallel for ( int i = 0; i < NUM_TEST_THREADS; i++ ) { testThreads[ i ].start(); } for ( int i = 0; i < NUM_TEST_THREADS; i++ ) { testThreads[ i ].join(); } With best regards, Grzegorz Dancewicz

1 0

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

Suppressing logging for select projects
by Mike Sukmanowsky 10 May '14

10 May '14

Hi there, We're currently developing project called streamparse which provides Pythonic tools for realtime stream development using Apache Storm. Although the project is Python-based, we maintain a command line interface, written in clojure, to provide JVM/Thrift interop capabilities https://github.com/Parsely/streamparse/tree/master/jvm. A requirement of one of our commands is to write a JSON object representation to STDOUT which our Python process would read and use downstream. The issue we have is that Apache Storm does some logging using logback upon calling certain functions which interferes with our expectation of only JSON being written to STDOUT. $ ./sparsej list --json 607 [main] INFO backtype.storm.thrift - Connecting to Nimbus at localhost:6627 [{"status":"ACTIVE","num-executors":52,"name":"meta_enricher","num-workers":4,"num-tasks":52,"uptime-secs":1211495,"id":"meta_enricher-49-1398354650"},{"status":"ACTIVE","num-executors":9,"name":"visits","num-workers":4,"num-tasks":9,"uptime-secs":53668,"id":"visits-7-1399512477"},{"status":"ACTIVE","num-executors":80,"name":"ptrack","num-workers":4,"num-tasks":80,"uptime-secs":76148,"id":"ptrack-3-1399489997"}] We added a logback-test.xml to a resources directory which is packaged with the JAR https://github.com/Parsely/streamparse/blob/master/jvm/resources/logback-te…. This isn't exactly what we want though since we really only need logging suppressed for the commands we run. What we're finding when our JAR is packaged with other dependencies is that all logging is suppressed. How can we go about suppressing logging for a single command like https://github.com/Parsely/streamparse/blob/master/jvm/src/streamparse/comm… ? Thanks! Mike -- Mike Sukmanowsky Product Lead, http://parse.ly 12 W 31st Street 8th floor New York, NY 10001 p: +1 (416) 953-4248 e: mike(a)parsely.com

3 2