How to roll log file on app shutdown in logback?

Question

I have a market data Spring Boot application that runs everyday and shuts itself down in the evening. After the app shuts down, I want to process the market data messages which were logged. In order to do that I was looking for a way to be able to rollover the log file at shutdown instead of startup so that my post processing app has a consistent way to read the files.

Currently, I have created a custom triggering policy and a using the following logback config for market data related messages

@NoAutoStart
public class CustomTriggerPolicy<E> extends SizeAndTimeBasedFNATP<E> {
    @Override
    public boolean isTriggeringEvent(File activeFile, E event) {
        boolean triggeringEvent = super.isTriggeringEvent(activeFile, event);
        if(!triggeringEvent) {
            elapsedPeriodsFileName = getCurrentPeriodsFileNameWithoutCompressionSuffix();
        }
        return triggeringEvent;
    }
}

logback.xml

<configuration>
    <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener"/>
    <shutdownHook class="ch.qos.logback.core.hook.DelayingShutdownHook">
        <delay>60000</delay>
    </shutdownHook>
    <appender name="MKT-DATA-FIX-LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_HOME}/mkt-data-fix.log</file>
        <append>false</append>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <Pattern>%m%n</Pattern>
        </encoder>

        <!-- rollover daily -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_HOME}/archived/foo/mkt-data-fix.%d{yyyy-MM-dd}.%i.gz</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="com.mkt.data.CustomTriggerPolicy">
                <maxFileSize>100GB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
    </appender>
</configuration>

SpringBootApplication.class (Main class)

@PreDestroy
    public void shutdown() {
        manualLogRollover();
    }

    public void manualLogRollover() {
        try {
            Set<Appender<ILoggingEvent>> loggingAppenders = AppenderUtils.getLoggingAppenders();
            AppenderUtils.rolloverAppenders(loggingAppenders);
        } catch (Exception e) {
            log.warn("Log rollover failed", e);
        }
    }

AppenderUtils.java

public class AppenderUtils {
    public static Set<Appender<ILoggingEvent>> getLoggingAppenders() {
        LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
        Set<Appender<ILoggingEvent>> fileLogAppenders = new HashSet<>();
        for(Logger logger : context.getLoggerList()) {
            for(Iterator<Appender<ILoggingEvent>> index = logger.iteratorForAppenders(); index.hasNext();) {
                Appender<ILoggingEvent> appender = index.next();
                if(appender instanceof RollingFileAppender) {
                    if(appender.getName().equals("MKT-DATA-FIX-LOG") ||
                            appender.getName().equals("MKT-DATA-FIX-EVENT-LOG")) {
                        fileLogAppenders.add(appender);
                    }
                }
            }
        }
        return fileLogAppenders;
    }

    public static void rolloverAppenders(Set<Appender<ILoggingEvent>> appenders) {
        for (Appender<ILoggingEvent> appender : appenders) {
            if (appender instanceof RollingFileAppender) {
                ((RollingFileAppender<ILoggingEvent>) appender).rollover();
            }
        }
    }
}

So far I've done the following things;

1. Tried the manual rollover at shutdown without the DelayingShutdownHook which ends up creating a .tmp file and doesn't finish the rollover process cleanly.
2. Add a delaying shutdown hook with a delay of 1 minute but it appears that logback Compressor's asyncCompress method returns a Future that times out after 30 seconds as a result of which I get the following error

18:16:58,872 |-ERROR in c.q.l.core.rolling.TimeBasedRollingPolicy@398887205 - Timeout while waiting for compression job to finish java.util.concurrent.TimeoutException
        at java.util.concurrent.TimeoutException
        at      at java.util.concurrent.FutureTask.get(FutureTask.java:205)
        at      at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.waitForAsynchronousJobToStop(TimeBasedRollingPolicy.java:137)
        at      at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.stop(TimeBasedRollingPolicy.java:129)
        at      at ch.qos.logback.core.rolling.RollingFileAppender.stop(RollingFileAppender.java:152)
        at      at ch.qos.logback.core.spi.AppenderAttachableImpl.detachAndStopAllAppenders(AppenderAttachableImpl.java:107)
        at      at ch.qos.logback.classic.Logger.detachAndStopAllAppenders(Logger.java:206)
        at      at ch.qos.logback.classic.Logger.recursiveReset(Logger.java:331)iam
        at      at ch.qos.logback.classic.Logger.recursiveReset(Logger.java:338)
        at      at ch.qos.logback.classic.Logger.recursiveReset(Logger.java:338)
        at      at ch.qos.logback.classic.Logger.recursiveReset(Logger.java:338)
        at      at ch.qos.logback.classic.Logger.recursiveReset(Logger.java:338)
        at      at ch.qos.logback.classic.LoggerContext.reset(LoggerContext.java:223)
        at      at ch.qos.logback.classic.LoggerContext.stop(LoggerContext.java:348)
        at      at ch.qos.logback.core.hook.ShutdownHookBase.stop(ShutdownHookBase.java:39)
        at      at ch.qos.logback.core.hook.DelayingShutdownHook.run(DelayingShutdownHook.java:57)
        at      at java.lang.Thread.run(Thread.java:748)

I am out of options. Does anyone know how to achieve what I am looking for here?

Answer 1

Maybe it will help someone.

Below is an example of how to use servlet to roll log file in logback on app when servlet container got a shutdown call.

The "ROLLING_FILES" we get from logback xml configuration file.

<appender name="ROLLING_FILES" class="com.g5e.store.log.event.LogAppenderConfiguration">

After that, we should override "rollover" method.

public class LogAppenderConfiguration<E> extends RollingFileAppender<E>
{ 
  @Override
  public void rollover() {
      super.rollover();
  }
}

Then we implement ServletContextListener to add a listener for the destroy event.

Get our appender and call "rollover" method on it.

@WebListener
public class LogServletContextListener implements ServletContextListener
{
  @Override
  public void contextDestroyed(ServletContextEvent arg0)
  {
    LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    LogAppenderConfiguration appender = (LogAppenderConfiguration) lc
        .getLogger(Logger.ROOT_LOGGER_NAME)
        .getAppender("ROLLING_FILES");

    appender.rollover();
  }

  @Override
  public void contextInitialized(ServletContextEvent arg0){}
}