Java CRaC support on static defined Loggers

[david-ic3]

What is the best practice to support Log4J when using CRaC ?

In our code loggers are defined statically (yes this is the problem but ideally we do not change this) :

public static final Logger GENERAL = Logger.getLogger("icCube.general");

The CRaC supported by :

        @Override
        public void beforeCheckpoint(Context<? extends Resource> context) throws Exception
        {
            LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false);
            loggerContext.stop();
        }

        @Override
        public void afterRestore(Context<? extends Resource> context) throws Exception
        {
            CdLog4jUtils.configure(xml); // here we reconfigure Log4J with a conf. file, fine

            LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false);
            loggerContext.start();
        }

Running now our code :

This works :  Logger.getLogger("icCube.general").info(message);
This does nothing : GENERAL.info(message);   // the static field

After restore the static logger are not bind to the 'new' Logger. Is there a way to rebind/reset the loggers or a best practice ?

[vy]

@david-ic3, we are not much familiar with CRaC. Would you mind providing a minimal single-Java-file example along with instructions to reproduce the failure, please?

[vy]

Judging from how Spring Framework implements CRaC support, we can do something similar for Log4j. What I'm concerned about is the extent of such a work. That is, your example snippet only covers RollingFileAppender and ConsoleAppender, but we have more stateful components, and some in different modules. That is, either every (Maven) module needs to provide its own CRaC integration, or Log4j Core should integrate its life cycle management with org.crac.Resource.

@david-ic3, would you be interested in contributing this feature?

P.S. Porting this to main (targeting Log4j 3) will not be trivial either; it will need a separate module for CRaC integration. Though we can figure that out once Log4j 2 is completed.

[marc-polizzi]

Contributing might be difficult as we're not familiar w/ all the Log4j features. We're using a very small part of it.

[marc-polizzi]

Giving you a single java file might not be easy. But I'll try to explain what we would need and what we've hacked until now.

With CRaC, the state (aka., checkpoint) of the JVM process can be stored to disk. Then later, the JVM can be started right from this self-contained state very quickly. E.g., even the already compiled bytecode is restored.

Before the checkpoint is actually made by the JVM, the application logic has to somehow disconnect itself from the external world : for example, files and sockets need to be closed. And upon restoration, the application will reconnect accordingly to the external world.

For that purpose, CRaC provides an entry point where we can register Resources that basically implements two methods :

beforeCheckpoint() {}
afterRestore() {}

So ideally, we would need somehow a way to do something like:

beforeCheckpoint() {
    LoggerContext.beforeCheckpointLogic()
}
afterRestore() {
    LoggerContext.afterRestoreLogic()
}

and having Log4j doing all the magic for the well known appenders ;-)

So far, this is what we've found and are doing assuming we've RollingFileAppender only - ConsoleAppender are working fine out of the box. In pseudo-code something like :

beforeCheckpoint() {
    LoggerContext.getConfiguration().getAppenders().forEach( rfa -> RollingFileUtils.closeOutputStream( rfa ); )
}
afterRestore() {
    LoggerContext.getConfiguration().getAppenders().forEach( rfa -> RollingFileUtils.openOutputStream( rfa ); )
}

with the helper code :

    /**
     * Replace the output stream by a NULL output stream and close the file output stream.
     */
    public static void closeOutputStream(RollingFileAppender appender)
    {
        final String fn = appender.getFileName();
        final OutputStreamManager manager = appender.getManager();

        if (manager.hasOutputStream())
        {
            try
            {
                final OutputStream os = manager.getOutputStream();

                manager.setOutputStream(NullOutputStream.INSTANCE);

                os.close();

            }
            catch (IOException ex)
            {
                throw new RuntimeException(ex);
            }
        }

    }

    /**
     * Replace the NULL output stream.
     */
    public static void openOutputStream(RollingFileAppender appender)
    {
        final String fn = appender.getFileName();
        final OutputStreamManager manager = appender.getManager();

        try
        {
            final OutputStream os = new FileOutputStream(fn, true);

            manager.setOutputStream(os);
        }
        catch (IOException ex)
        {
            throw new RuntimeException(ex);
        }
    }

So far, it seems to work nicely and we are able to checkpoint and restore our Java application with Log4j still working as expected.

It would be nice to have this kind of support built in Log4j somehow. Right now, I've the feeling that our code is a bit of a hack ;-)

Let me know if you need more information.

[ppkarwasz]

Log4j Core does define a LifeCycle interface, and many Core plugins implement it. In principle this means that calling AbstractConfiguration#stop() and then AbstractConfiguration#start() could be used to restart the logging system.

However, LifeCycle support in Log4j Core is currently inconsistent and largely untested, especially for appenders. For example:

• Most file-based appenders open files in their constructors rather than in start().
• As a result, calling stop() followed by start() will not correctly re-acquire file resources.
• Similar issues exist in other components which manage I/O resources.

Improving this is feasible but non-trivial. It would require refactoring components to follow a consistent LifeCycle contract:

• Resource acquisition should happen in start(), not in the constructor.
• Resource release should happen in stop().
• Components should be prepared to operate through multiple start/stop cycles.

We could make progress incrementally by addressing the most commonly used components first:

1. ConsoleAppender
2. FileAppender, RandomAccessFileAppender and MemoryMappedFileAppender,
3. RollingFileAppender and RollingRandomcAccessFileAppender
4. Others (e.g. socket appenders, JDBC appender, etc.)

This is an area where contributions are welcome.

On Managers (FileManager, etc.)

Managers like FileManager are not good candidates for restart logic. They are designed as thin wrappers around resources and are cached globally via the AbstractManager registry. Once a FileManager is closed, it unregisters itself from the AbstractManager registry and should not be reused. Restarting a configuration should create new managers rather than trying to restart old ones.

A better approach would be to:

• Move creation of managers (like FileManager) out of the appender constructor/builder.
• Instantiate managers inside the appender's start() method instead.
• Ensure stop() closes and unregisters managers properly.