<div dir="ltr">All,<div><br></div><div>I'm using RollingFileAppender under jetty, and it occasionally seems to overwrite the contents of log files it has rotated in the past. My logback configuration is attached. Also attached is a terminal session in which you can see that the first line of the rotated log files *usually* is from the right timeframe, but occasionally is from a completely different time. For example, the file named jetty/logs/app.2013-07-22-1000.log contains a log message from the 1300 hour. In those cases, the messages that were once in that log file have been overwritten. Also in that terminal session is the contents of /proc/xxx/fd for the jetty process, where you can see that the process is maintaining open file descriptors to past rotated files. That seems like a bug to me. I see this same behavior with both logback versions 0.9.28 and 1.0.13. I'm using jetty 7.3.1.v20110307.</div>
<div><br></div><div>I would appreciate any pointers you could give to help me track this down. If it's just a simple misconfiguration on my part, I'd love to know that, too, of course. I've searched for past mentions of this behavior and haven't found one. Apologies if I overlooked any that exist.</div>
<div><br></div><div>Thanks,</div><div>Sean</div><div><br></div><div><br></div><div>=== Configuration ===</div><div><br></div><div><div><configuration></div><div> <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"></div>
<div> <file>logs/nmr.log</file></div><div> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"></div><div> <fileNamePattern>logs/nmr.%d{yyyy-MM-dd-HH}00.log</fileNamePattern></div>
<div> <maxHistory>672</maxHistory></div><div> </rollingPolicy></div><div> <encoder></div><div> <pattern>%date [%thread] %-5level %msg%n</pattern></div><div> </encoder></div>
<div> </appender></div><div> <appender name="EMAIL" class="ch.qos.logback.classic.net.SMTPAppender"></div><div> <evaluator class="RateLimitingEvaluator" /></div><div> <smtpHost>localhost</smtpHost></div>
<div> <to><a href="mailto:jetty-errors@company.com">jetty-errors@company.com</a></to></div><div> <from>Jetty Errors &<a href="mailto:lt%3Bjetty-errors@company.com">lt;jetty-errors@company.com</a>></from></div>
<div> <subject>%mdc{environment} %mdc{shard} error: %msg</subject></div><div> <layout class="ch.qos.logback.classic.PatternLayout"></div><div> <pattern>Date: %date%n{}Message: %msg%n{}Context: %mdc%n</pattern></div>
<div> </layout></div><div> <cyclicBufferTracker class="ch.qos.logback.core.spi.CyclicBufferTrackerImpl"></div><div> <bufferSize>1</bufferSize> <!-- send just one log entry per email --></div>
<div> </cyclicBufferTracker></div><div> </appender></div><div> <root level="INFO"></div><div> <appender-ref ref="FILE" /></div><div> <appender-ref ref="EMAIL" /></div>
<div> </root></div><div></configuration></div></div><div><br></div><div><br></div><div>=== Notes from terminal session ===</div><div><br></div><div><div>user@host:/var/local/webapp$ head -1 jetty/logs/app.2013-07-22-*</div>
<div>==> jetty/logs/app.2013-07-22-0000.log <==</div><div>2013-07-22 00:00:06,253 [qtp28715691-220085] INFO ...</div><div>==> jetty/logs/app.2013-07-22-0100.log <==</div><div>2013-07-22 01:00:04,447 [qtp28715691-220283] INFO ...</div>
<div>==> jetty/logs/app.2013-07-22-0200.log <==</div><div>2013-07-22 10:00:04,406 [qtp28715691-221647] INFO ...</div><div>==> jetty/logs/app.2013-07-22-0300.log <==</div><div>2013-07-22 03:00:00,047 [qtp28715691-220456] INFO ...</div>
<div>==> jetty/logs/app.2013-07-22-0400.log <==</div><div>2013-07-22 04:00:00,621 [qtp28715691-220497] INFO ...</div><div>==> jetty/logs/app.2013-07-22-0500.log <==</div><div>2013-07-22 05:00:03,765 [qtp28715691-220332] INFO ...</div>
<div>==> jetty/logs/app.2013-07-22-0600.log <==</div><div>2013-07-22 06:00:02,535 [qtp28715691-220805] INFO ...</div><div>==> jetty/logs/app.2013-07-22-0700.log <==</div><div>2013-07-22 07:00:02,687 [qtp28715691-221141] INFO ...</div>
<div>==> jetty/logs/app.2013-07-22-0800.log <==</div><div>2013-07-22 08:00:00,891 [qtp28715691-220805] INFO ...</div><div>==> jetty/logs/app.2013-07-22-0900.log <==</div><div>2013-07-22 09:00:00,537 [qtp28715691-221493] INFO ...</div>
<div>==> jetty/logs/app.2013-07-22-1000.log <==</div><div>2013-07-22 13:00:00,000 [qtp28715691-222323] INFO ...</div><div>==> jetty/logs/app.2013-07-22-1100.log <==</div><div>2013-07-22 11:00:02,096 [qtp28715691-221933] INFO ...</div>
<div>==> jetty/logs/app.2013-07-22-1200.log <==</div><div>2013-07-22 12:00:00,054 [qtp28715691-222149] INFO ...</div><div>==> jetty/logs/app.2013-07-22-1300.log <==</div><div>2013-07-22 13:12:57,841 [qtp28715691-222370] INFO ...</div>
<div>user@host:/var/local/webapp$ ps auxww | grep -v grep | grep jetty</div><div>jetty 13570 2.8 1.3 1153892 870036 ? Sl May13 2832:30 /usr/bin/java -Xss1m -Xmx128m -Duser.timezone=America/Los_Angeles -Djetty.port=30800 -jar start.jar</div>
<div>user@host:/var/local/webapp$ sudo ls -l /proc/13570/fd | grep 'app\.'</div><div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 102 -> /var/local/webapp/jetty/logs/app.log</div><div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 105 -> /var/local/webapp/jetty/logs/app.2013-06-12-1400.log (deleted)</div>
<div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 112 -> /var/local/webapp/jetty/logs/app.2013-06-26-1600.log</div><div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 118 -> /var/local/webapp/jetty/logs/app.2013-07-17-1600.log</div>
<div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 122 -> /var/local/webapp/jetty/logs/app.2013-06-11-1100.log (deleted)</div><div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 130 -> /var/local/webapp/jetty/logs/app.2013-07-22-0200.log</div>
<div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 144 -> /var/local/webapp/jetty/logs/app.2013-07-22-1000.log</div><div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 20 -> /var/local/webapp/jetty/logs/app.2013-07-15-1400.log</div>
<div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 4 -> /var/local/webapp/jetty/logs/app.2013-07-22-1300.log</div><div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 85 -> /var/local/webapp/jetty/logs/app.2013-07-10-1200.log</div>
<div>l-wx------ 1 jetty jetty 64 Jul 22 14:03 99 -> /var/local/webapp/jetty/logs/app.2013-07-10-1000.log</div></div><div><br></div><div><br></div></div>