[logback-user] Logging outage in WebLogic with RollingFileAppender

ceki ceki at qos.ch
Wed Apr 17 11:59:57 CEST 2013


It very much helps to set <configuration debug="true">  when diagnosing 
logback-related problems. If debug="true" logback might actually tell 
you why it stops logging after app restart. I suspect that the 
underlying issue is caused by jmxConfigurator which probably throws an 
exception the second time it is started in your particular environment.



On 17.04.2013 11:45, Roxolid wrote:
> Hi Ceki,
>
> first of all, here is my configuration file, I'm copy-pasting it as we
> have (is almost identical to the one from all applications we develop now):
>
> <?xml version="1.0" encoding="UTF-8"?>
> <configuration debug="false">
>      <contextName>TST-LOGBACK</contextName>
>      <jmxConfigurator/>
>
>      <turboFilter class="ch.qos.logback.classic.turbo.MarkerFilter">
>          <Marker>PROFILER</Marker>
>          <OnMatch>ACCEPT</OnMatch>
>      </turboFilter>
>
>      <property name="AUDIT_LOG_DIR" value="/export/home/oracle/TESTS/tst" />
>      <property name="AUDIT_LOG_FILE" value="tst-logback-audit.log" />
>      <property name="PERF_LOG_DIR" value="/export/home/oracle/TESTS/tst" />
>      <property name="PERF_LOG_FILE" value="tst-logback-perf.log" />
>      <property name="LOG_DIR" value="/export/home/oracle/TESTS/tst" />
>      <property name="LOG_FILE" value="tst-logback.log" />
>      <property name="LOG_FILE_ROLLING" value="tst-logback" />
>
>      <appender name="FILE"
> class="ch.qos.logback.core.rolling.RollingFileAppender">
>          <prudent>true</prudent>
>          <rollingPolicy
> class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
>              <!-- daily rollover with
> ${LOG_DIR}/${LOG_FILE_ROLLING}_%d{yyyy-MM-dd}.log -->
>              <!-- hourly rollover with
> ${LOG_DIR}/${LOG_FILE_ROLLING}_%d{yyyy-MM-dd_HH}.log -->
>              <!-- every minute rollover with
> ${LOG_DIR}/${LOG_FILE_ROLLING}_%d{yyyy-MM-dd_HH_mm}.log -->
>
> <fileNamePattern>${LOG_DIR}/${LOG_FILE_ROLLING}_%d{yyyy-MM-dd_HH}.log</fileNamePattern>
>              <!-- keep 30 days' worth of history -->
>              <maxHistory>48</maxHistory>
>          </rollingPolicy>
>          <encoder>
>              <pattern>%date %level [%thread] %logger{10} [%file:%line]
> %msg%n</pattern>
>          </encoder>
>      </appender>
>
>      <appender name="AUDIT_FILE" class="ch.qos.logback.core.FileAppender">
>          <file>${AUDIT_LOG_DIR}/${AUDIT_LOG_FILE}</file>
>          <encoder>
>              <pattern>%date %level %logger{10} %msg%n</pattern>
>          </encoder>
>      </appender>
>
>      <appender name="PERF_FILE" class="ch.qos.logback.core.FileAppender">
>          <file>${PERF_LOG_DIR}/${PERF_LOG_FILE}</file>
>          <encoder>
>              <pattern>%date [%thread] %logger{10} %msg%n</pattern>
>          </encoder>
>      </appender>
>
>      <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
>          <encoder>
>              <pattern>%date %level [%file:%line] %msg</pattern>
>          </encoder>
>      </appender>
>
>      <logger name="com.oracle.sk.tst" level="trace" additivity="false">
>          <appender-ref ref="FILE" />
>      </logger>
>
>      <logger name="com.oracle.sk.tst.logback.TestLogbackServlet"
> level="info" additivity="false">
>          <appender-ref ref="FILE" />
>      </logger>
>
>      <logger name="AUDITOR" level="trace" additivity="false">
>          <appender-ref ref="AUDIT_FILE" />
>      </logger>
>
>      <logger name="PROFILER" level="debug" additivity="false">
>          <appender-ref ref="PERF_FILE" />
>      </logger>
>
>      <root level="OFF">
>          <appender-ref ref="FILE" />
>      </root>
> </configuration>
>
> The prudent flag is there because I had troubles with truncating log
> files by our test people. They use "cat /dev/null/ >
> tst-logback_2013-04-17_10.log" to clear the log when they start testing.
> Without "prudent", application was not able to recover from it and was
> not logging anymore.
>
> Maybe you want to look at complete testing project I use for solving
> this issue. I try to attach it to this email (don't know if attachments
> are allowed for this mailing list). And if you wish I can provide you
> with small (~2 min, ~13MB, FLV) video demostrating the behavior.
>
> I did further testing and found one thing - after stopping and starting
> the app it was not able to recover even after rollover (on my dev
> machine with the testing project). The report from testing team says
> that they've seen it recovers when the new log file was rolled out,
> however now no one can remember if really :-) So I consider this as
> "not, it didn't recover" - at least I'm not able to prove that.
>
> So after all, when I stop/start the app, it will stop logging...
>
> Thank you for your help, I really appreciate it.
>
> Regards,
> rox
>
> P.S.: BTW, even it has no impact to this issue, just for interest's
> sake, I think I found why I had lc.reset() in my code - in
> documentation, the example uses stop(), however the text above mentions
> reset().
>
>
>
> On Tue, Apr 16, 2013 at 5:31 PM, ceki <ceki at qos.ch <mailto:ceki at qos.ch>>
> wrote:
>
>
>     LoggerContext.close() is almost identical to
>     LoggerContext.reset(). Here is the code:
>
>     class LoggerContext ... {
>
>        public void stop() {
>          reset();
>          fireOnStop();
>          resetAllListeners();
>          started = false;
>        }
>     }
>
>     I don't think calling reset or close should make a difference. You
>     want to release and close appenders which reset() does.  Could you
>     post your configuration file?
>
>
>     On 16.04.2013 16:59, Roxolid wrote:
>
>         Hi Ceki,
>
>         well, half-true in my case... I have that code in my
>         contextDestroyed(..) method, however, for whatever reason I have
>         lc.reset() instead of lc.stop there... Will change and test that
>         once
>         I'm back to my dev machine. I will let you know then.
>
>         Thank you for your help.
>
>         Regards,
>         rox
>
>
>
>         On Tue, Apr 16, 2013 at 4:01 PM, ceki <ceki at qos.ch
>         <mailto:ceki at qos.ch> <mailto:ceki at qos.ch <mailto:ceki at qos.ch>>>
>
>         wrote:
>
>              Hi Rox,
>
>              Are you stopping logback when your application is stopped
>         (and then
>              started)? The conextDestroyed method of
>              javax.servlet.____ServletContextListener is a good place
>         for invoking
>              such code:
>
>              import javax.servlet.____ServletContextListener;
>              import javax.servlet.____ServletContextEvent;
>              import org.slf4j.LoggerFactory;
>              import ch.qos.logback.classic.____LoggerContext;
>
>
>              public class MyServletContextListener implements
>                                                     ServletContextListener {
>
>                 public void contextInitialized(____ServletContextEvent
>         sce) {
>                 }
>
>                 public void contextDestroyed(____ServletContextEvent sce)  {
>                   LoggerContext lc =
>                             (LoggerContext)
>         LoggerFactory.____getILoggerFactory();
>
>                   lc.stop();
>              }
>
>              Please let us know if stopping logback as described above
>         helps.
>
>
>              On 16.04.2013 15:06, Roxolid wrote:
>
>                  Hi all,
>
>                  I have a trouble with logback configuration under
>         WebLogic 12c. My
>                  application is using RollingFile Appender with
>                  TimeBasedRollingPolicy
>                  and the problem is it stops logging every time I stop
>         and then
>                  start the
>                  application through WebLogic Console. However, the
>         logging is
>                  back when
>                  a rollover occurs - in the new file logging continues...
>
>                  Has anyone faced such behavior (and knows the solution)?
>
>                  Thank you in advance.
>
>                  Regards,
>
>                  rox
>
>
>

-- 
Ceki
65% of statistics are made up on the spot


More information about the Logback-user mailing list