10

I have created an EnvironmentPostProcessor in SpringBoot to fetch properties from database and attached it to the Spring's Environment as a PropertySource.

This is the code I have:

@Override
public void postProcessEnvironment(ConfigurableEnvironment environment, SpringApplication application) {
    Map<String, Object> propertySource = new HashMap<>();
    // LOG SOMETHING HERE *******************
    logger.error("AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA");
    String[] activeProfiles = environment.getActiveProfiles();
    String[] defaultProfiles = environment.getDefaultProfiles();

    // Do not pull db configuration when 'default' profile (used by Jenkins only) is run 
    if (activeProfiles.length == 0 && defaultProfiles[0] == "default") { 
        return;
    }

    // Load properties for Config schema
    String dataSourceUrl = environment.getProperty("service.datasource.url");
    String username = environment.getProperty("service.datasource.username");
    String password = environment.getProperty("service.datasource.password");
    String driver = environment.getProperty("service.datasource.driverClassName");

    try {
        // Build manually datasource to Config
        DataSource ds = DataSourceBuilder
                .create()
                .username(username)
                .password(password)
                .url(dataSourceUrl)
                .driverClassName(driver)
                .build();

        // Fetch all properties
        PreparedStatement preparedStatement = ds.getConnection().prepareStatement("SELECT name, value FROM propertyConfig WHERE service = ?");
        preparedStatement.setString(1, APP_NAME);

        ResultSet rs = preparedStatement.executeQuery();

        // Populate all properties into the property source
        while (rs.next()) {
            String propName = rs.getString("name");
            propertySource.put(propName, rs.getString("value"));
        }

        // Create a custom property source with the highest precedence and add it to Spring Environment 
        environment.getPropertySources().addFirst(new MapPropertySource(PROPERTY_SOURCE_NAME, propertySource));

    } catch (Exception e) {
        throw new Exception("Error fetching properties from ServiceConfig");
    }
}

And this is the main/META-INF/spring-factories file had to be created:

# Environment Post Processor
org.springframework.boot.env.EnvironmentPostProcessor=com.blabla.config.ReadDbPropertiesPostProcessor

The code works well, it fetches from the db what I need. However, I would like to log information about this in case something wrong occurs, for instance if db is down I want to log an error and stop the app to start. My app is configured to use logger and not the console.

I have tried logging the error, throwing exceptions, also printing out something but my log is never logging this information.

How can I do to use the logger during this early spring stage? Is it possible to do this in anyway? Am I using EnvironmentPostProcessor wrongly?

1

5 Answers 5

13

The problem here is that logging system initialized only after spring context is initialized. When the log method is invoked the log system does not know what to do with the information and it does nothing.

There is no elegant way to solve this issue. You either get rid of spring-managed log system or use deferred log mechanisms (just like spring does internally).

To be able to use DeferredLog you have to make sure that after context initialization the system will request to replay logs.

Here is one of the ways how it could be achieved:

@Component
public class MyEnvironmentPostProcessor implements
        EnvironmentPostProcessor, ApplicationListener<ApplicationEvent> {

    private static final DeferredLog log = new DeferredLog();

    @Override
    public void postProcessEnvironment(
            ConfigurableEnvironment env, SpringApplication app) {
        log.error("This should be printed");
    }

    @Override
    public void onApplicationEvent(ApplicationEvent event) {
        log.replayTo(MyEnvironmentPostProcessor.class);
    }
}

In this example every log message is cached in the DeferredLog. And once the context initialized the system will call onApplicationEvent. This method will replay all the cached log-events to the standard logger.

NOTE: I used ApplicationListener here but you can use every convenient way. The idea is to call DeferredLog.replayTo() once context initialized and it does not matter from which place you call it.

PS: The location of spring.factories should be src/main/resources/META-INF otherwise postProcessEnvironment might not be invoked.

8
  • thank you for the answer. It's very helpful... going to test this right now. Would like to clarify something, how do I tie the ApplicationEvent? Is there a place to subscribe/register to these events or is this automatically detected by springboot? Commented Mar 16, 2017 at 20:13
  • 1
    Once you implement ApplicationListener and annotate your class with @Component spring will automatically subscribe it to ApplicationEvent. Commented Mar 16, 2017 at 20:24
  • 1
    You delegate spring with responsibility to setup logger for you. If spring fails to start there is no good way to recover log system. As I said you can setup log by yourself (without spring) but it will be problematic or even impossible. Anyway I think this is not the way to go. I recommend you to rethink your configuration. EnvironmentPostProcessor is not the best place to query for database. Ideally there should not be any exceptions thrown from this place. I'm pretty sure you can solve your task by querying DB from some other place. Commented Mar 16, 2017 at 22:25
  • 1
    I don't know your domain area and unfortunately I can't propose the solution. But if you have such a strict requirement I recommend you to investigate dipper how spring itself fights with this problem. The idea is that each part of spring is loaded with its own order. You can play around with EnvironmentPostProcessor to make sure that it is loaded after log system. Take a look on an example from spring sources: SpringApplicationJsonEnvironmentPostProcessor. It uses Ordered interface to run the config in right timeframe. Not sure that it will help you but you have to try for sure. Commented Mar 16, 2017 at 22:54
  • 2
    FWIW this isn't working for me. Despite being static, I get a different instance of DeferredLogger when the event is fired, which results in nothing being logged. Commented Oct 10, 2017 at 12:19
9

As noted in the accepted answer, the problem is the logging system isn't initialized yet when EnvironmentPostProcessors are run.

However, using a mechanism like a static DeferredLog in EnvironmentPostProcessor to store the logs temporarily, then replay them in a ApplicationListener<ApplicationPreparedEvent> (once the logging system is initialized) does not work either because the EnvironmentPostProcessor and ApplicationListener are loaded and initialized by different class loaders.

Because of that, the instance of the Class used for the ApplicationListener has no visibility into the instance of the Class used as the EnvironmentPostProcessor (even if they are in fact the same class).

One hack would be to use System.setProperty(...) to set what you want to log out in the EnvironmentPostProcessor, and System.getProperty(...) in the ApplicationListener to log it out. This avoids the issue with Spring's class loaders. I definitely recommend against using this approach, but it does work.

YMMV, but in my case I found that moving the custom environment setup logic from an EnvironmentPostProcessor to an ApplicationListener<ApplicationPreparedEvent> worked just fine for me, logging included.

Spring Application Events reference: https://docs.spring.io/spring-boot/docs/2.2.6.RELEASE/reference/html/spring-boot-features.html#boot-features-application-events-and-listeners


UPDATE: Based on shaohua-shi's answer, here is a simple working solution that uses an ApplicationContextInitializer to replay a DeferredLog after the logging system has been initialized:

public class MyEnvPostProcessor implements EnvironmentPostProcessor {

    private DeferredLog log = new DeferredLog();

    @Override
    public void postProcessEnvironment(ConfigurableEnvironment env, SpringApplication app) {
        app.addInitializers(ctx -> log.replayTo(MyEnvPostProcessor.class));

        log.warn("In Env Post Processor");
    }
}

Log:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.1.RELEASE)

2020-06-25 20:51:15.118  WARN 7297 --- [  restartedMain] c.e.testenvpostproc.MyEnvPostProcessor   : In Env Post Processor
1
  • This is a beautiful workaround, thank you :)
    – adarshr
    Commented Sep 27, 2022 at 10:42
6

I understand this question was initially asked years ago before Spring 2.4, but for people who come across this post now, I hope this helps.

In the JavaDocs for EnvironmentPostProcessor you can see:

"Since Spring Boot 2.4, EnvironmentPostProcessor implementations may optionally take the following constructor parameters:

  • DeferredLogFactory - A factory that can be used to create loggers with output deferred until the application has been fully prepared (allowing the environment itself to configure logging levels)."
import org.apache.commons.logging.Log;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.env.EnvironmentPostProcessor;
import org.springframework.boot.logging.DeferredLogFactory;
import org.springframework.core.env.ConfigurableEnvironment;

public class MyEnvironmentPostProcessor implements EnvironmentPostProcessor {
    private final Log log;

    public MyEnvironmentPostProcessor(DeferredLogFactory logFactory) {
        log = logFactory.getLog(MyEnvironmentPostProcessor.class);
    }
    
    @Override
    public void postProcessEnvironment(ConfigurableEnvironment environment, SpringApplication application) {
        log.info("My log statement.");
    }
}
0
3

I found! invoke addInitializers when you execut postProcessEnvironment.

public class MyEnvironmentProcessor implements EnvironmentPostProcessor, Ordered {

    public static final int ORDER = Ordered.LOWEST_PRECEDENCE - 6;

    private DeferredLog logger = new DeferredLog();

    @Override
    public void postProcessEnvironment(ConfigurableEnvironment env, SpringApplication app) {
        app.addInitializers(new MyContextInitializer(this));
        logger.error("---------------MyEnvironmentProcessor---------------");
    }
    public DeferredLog getLogger() {
        return logger;
    }
}
public class MyContextInitializer implements ApplicationContextInitializer<ConfigurableApplicationContext> {

    private final Logger logger = LoggerFactory.getLogger(I3keContextInitializer.class);

    MyEnvironmentProcessor processor;

    public MyContextInitializer(MyEnvironmentProcessor processor) {
        this.processor = processor;
    }

    @Override
    public void initialize(ConfigurableApplicationContext applicationContext) {
        logger.warn("------------> DeferredLog:");
        processor.getLogger().replayTo(MyEnvironmentProcessor.class);
    }
}

show log

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.0.RELEASE)

06-10 15:48:59.874  WARN 38518 --- [restartedMain] c.s.e.init.MyContextInitializer       |21 : ------------> DeferredLog:
06-10 15:48:59.885 ERROR 38518 --- [restartedMain] c.s.e.e.MyEnvironmentProcessor        |231 : ---------------MyEnvironmentProcessor---------------
1
1

For those coding in Kotlin:

class SomePostProcessor : EnvironmentPostProcessor {

    var logger: DeferredLog = DeferredLog()

    override fun postProcessEnvironment(env: ConfigurableEnvironment, application: SpringApplication) {
        // do and log stuff
        logger.info("some log message")

        // HERE IS THE TRICK: defer logging to after the application starts
        application.addInitializers(ApplicationContextInitializer<ConfigurableApplicationContext> {
            logger.replayTo(ExcludeAutoConfigPostProcessor::class.java)
        })
    }
}

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.