SpringBoot DataSource initialization can be invoked after the wrong EntityManager has initialized

I have configured my application to use two data sources. And I want data.sql to run on my primary datasource. But everytime I start the application I can see data.sql is executed on wrong datasource ( not primary ) and even before any model classes are initiated ( so it can create the tables, columns first ).

See my codes below.

data.sql is run for this wrong data source.

import org.springframework.beans.factory.annotation.Qualifier
import org.springframework.boot.context.properties.ConfigurationProperties
import org.springframework.boot.jdbc.DataSourceBuilder
import org.springframework.boot.orm.jpa.EntityManagerFactoryBuilder
import org.springframework.context.annotation.Bean
import org.springframework.context.annotation.Configuration
import org.springframework.data.jpa.repository.config.EnableJpaRepositories
import org.springframework.orm.jpa.JpaTransactionManager
import org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean
import org.springframework.transaction.PlatformTransactionManager
import org.springframework.transaction.annotation.EnableTransactionManagement
import javax.persistence.EntityManagerFactory
import javax.sql.DataSource

@Configuration
@EnableTransactionManagement
@EnableJpaRepositories(entityManagerFactoryRef = "organisationServiceEntityManagerFactory", transactionManagerRef = "ost")
class OrganisationServiceDataConfig {

    @Bean(name = ["organisationServiceEntityManagerFactory"])
    fun organisationServiceEntityManagerFactory(
        builder: EntityManagerFactoryBuilder,
        @Qualifier("organisationServiceDataSource") dataSource: DataSource
    ): LocalContainerEntityManagerFactoryBean {
        return builder
            .dataSource(dataSource)
            .packages("com.dovetaillab.consentapi.adminwebservice.model.organisationservice")
            .persistenceUnit("organisationservice")
            .build()
    }

    @Bean(name = ["organisationServiceDataSource"])
    @ConfigurationProperties(prefix = "spring.datasource-organisationservice")
    fun organisationServiceDataSource(): DataSource {
        return DataSourceBuilder.create().build()
    }

    @Bean
    fun ost(@Qualifier("organisationServiceEntityManagerFactory") organisationServiceEntityManagerFactory: EntityManagerFactory): PlatformTransactionManager {
        return JpaTransactionManager(organisationServiceEntityManagerFactory)
    }
}

My primary datasource

package com.dovetaillab.consentapi.adminwebservice.config.datasources

import org.springframework.beans.factory.annotation.Qualifier
import org.springframework.boot.context.properties.ConfigurationProperties
import org.springframework.boot.jdbc.DataSourceBuilder
import org.springframework.boot.orm.jpa.EntityManagerFactoryBuilder
import org.springframework.context.annotation.Bean
import org.springframework.context.annotation.Configuration
import org.springframework.context.annotation.Primary
import org.springframework.data.jpa.repository.config.EnableJpaRepositories
import org.springframework.orm.jpa.JpaTransactionManager
import org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean
import org.springframework.transaction.PlatformTransactionManager
import org.springframework.transaction.annotation.EnableTransactionManagement
import javax.persistence.EntityManagerFactory
import javax.sql.DataSource

@Configuration
@EnableTransactionManagement
@EnableJpaRepositories(entityManagerFactoryRef = "primaryEntityManagerFactory", transactionManagerRef = "pt")
class PrimaryDataConfig {

    @Bean(name = ["primaryEntityManagerFactory"])
    @Primary
    fun primaryEntityManagerFactory(
        builder: EntityManagerFactoryBuilder,
        @Qualifier("primaryBaseDataSource") dataSource: DataSource
    ): LocalContainerEntityManagerFactoryBean {
        return builder
            .dataSource(dataSource)
            .packages("com.dovetaillab.consentapi.adminwebservice.model.primary")
            .persistenceUnit("primary")
            .build()
    }

    @Primary
    @Bean(name = ["primaryBaseDataSource"])
    @ConfigurationProperties(prefix = "spring.datasource")
    fun primaryBaseDataSource(): DataSource {
        return DataSourceBuilder.create().build()
    }

    @Primary
    @Bean
    fun pt(@Qualifier("primaryEntityManagerFactory") primaryEntityManagerFactory: EntityManagerFactory): PlatformTransactionManager {
        return JpaTransactionManager(primaryEntityManagerFactory)
    }
}

Application.properties

spring:
  jpa:
    generate-ddl: true
    hibernate:
      ddl-auto: update
    properties:
      hibernate:
        jdbc:
          lob:
            non_contextual_creation: true
        dialect: org.hibernate.dialect.PostgreSQLDialect

  datasource:
    jdbc-url: jdbc:postgresql://localhost:5432/maindb
    username: main_user
    password: admin
    driver-class-name: org.postgresql.Driver
    initialization-mode: always
    continue-on-error: false

  datasource-organisationservice:
    jdbc-url: jdbc:postgresql://localhost:5432/organisationservice
    username: organisationservice_user
    password: admin
    driver-class-name: org.postgresql.Driver

Any idea why ?

Comment From: philwebb

It's quite hard to tell if this is a bug or a problem with your application configuration. Could you please provide a sample application that we can run so that we can debug the issue (If possible, in Java)?

Comment From: mrifni

I am attaching a minimal sample project here. Its very easy to run. demo 3.zip

// this will create the database server and create two databases.
docker-compose -f docker-compose.yml up postgresql

// to run the application.
 ./gradlew bootRun

You will get the below error on first run (on second run and on wards you will get sql constraint error, thats because script already ran once). The error is happening because data.sql is executed on the wrong datasource initialization, and also before entities are loaded to create tables.

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2019-11-01 08:42:50.612 ERROR 32491 --- [           main] o.s.boot.SpringApplication               : Application run failed

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'organisationServiceEntityManagerFactory' defined in class path resource [com/example/demo/OrganisationServiceDataConfig.class]: Initialization of bean failed; nested exception is org.springframework.jdbc.datasource.init.ScriptStatementFailedException: Failed to execute SQL script statement #1 of URL [file:/Users/mohamed.rifni/Downloads/demo%203/build/resources/main/data.sql]: INSERT INTO public.users(id, cognito_id, email, organisation) VALUES (10001, '44d8d57a-38ff-4a04-a71a-e6f1dce29f73', 'mohamed+admin@abc.com', 10001); nested exception is org.postgresql.util.PSQLException: ERROR: relation "public.users" does not exist
  Position: 13
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:603) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1108) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:868) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:141) ~[spring-boot-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:747) ~[spring-boot-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397) ~[spring-boot-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:315) ~[spring-boot-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226) ~[spring-boot-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1215) ~[spring-boot-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at com.example.demo.DemoApplicationKt.main(DemoApplication.kt:13) ~[main/:na]
Caused by: org.springframework.jdbc.datasource.init.ScriptStatementFailedException: Failed to execute SQL script statement #1 of URL [file:/Users/mohamed.rifni/Downloads/demo%203/build/resources/main/data.sql]: INSERT INTO public.users(id, cognito_id, email, organisation) VALUES (10001, '44d8d57a-38ff-4a04-a71a-e6f1dce29f73', 'mohamed+admin@abc.com', 10001); nested exception is org.postgresql.util.PSQLException: ERROR: relation "public.users" does not exist
  Position: 13
        at org.springframework.jdbc.datasource.init.ScriptUtils.executeSqlScript(ScriptUtils.java:626) ~[spring-jdbc-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.jdbc.datasource.init.ResourceDatabasePopulator.populate(ResourceDatabasePopulator.java:254) ~[spring-jdbc-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.jdbc.datasource.init.DatabasePopulatorUtils.execute(DatabasePopulatorUtils.java:49) ~[spring-jdbc-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.boot.autoconfigure.jdbc.DataSourceInitializer.runScripts(DataSourceInitializer.java:202) ~[spring-boot-autoconfigure-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.autoconfigure.jdbc.DataSourceInitializer.initSchema(DataSourceInitializer.java:119) ~[spring-boot-autoconfigure-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.autoconfigure.jdbc.DataSourceInitializerInvoker.onApplicationEvent(DataSourceInitializerInvoker.java:89) ~[spring-boot-autoconfigure-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.autoconfigure.jdbc.DataSourceInitializerInvoker.onApplicationEvent(DataSourceInitializerInvoker.java:37) ~[spring-boot-autoconfigure-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:403) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:360) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher.publishEventIfRequired(DataSourceInitializedPublisher.java:99) ~[spring-boot-autoconfigure-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher.postProcessAfterInitialization(DataSourceInitializedPublisher.java:90) ~[spring-boot-autoconfigure-2.2.0.RELEASE.jar:2.2.0.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsAfterInitialization(AbstractAutowireCapableBeanFactory.java:431) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1807) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:595) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        ... 15 common frames omitted
Caused by: org.postgresql.util.PSQLException: ERROR: relation "public.users" does not exist
  Position: 13
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2497) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2233) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:310) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:446) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:370) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:311) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:297) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:274) ~[postgresql-42.2.8.jar:42.2.8]
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:269) ~[postgresql-42.2.8.jar:42.2.8]
        at com.zaxxer.hikari.pool.ProxyStatement.execute(ProxyStatement.java:95) ~[HikariCP-3.4.1.jar:na]
        at com.zaxxer.hikari.pool.HikariProxyStatement.execute(HikariProxyStatement.java) ~[HikariCP-3.4.1.jar:na]
        at org.springframework.jdbc.datasource.init.ScriptUtils.executeSqlScript(ScriptUtils.java:605) ~[spring-jdbc-5.2.0.RELEASE.jar:5.2.0.RELEASE]
        ... 31 common frames omitted


> Task :bootRun FAILED

Comment From: snicoll

@mrifni thanks for the sample. Unfortunately I don't think your analysis is correct. If you debug this application, you could see that the database initialization is happening on the mainDb. The organisationServiceEntityManagerFactory part is misleading, I agree.

Datasource initialization happens in DataSourceInitializedPublisher (that's a bean post processor). It will initialize the datasource as soon as it sees a JPA entity manager. In this case it sees your organization entity manager and invokes database initialization that fails.

That's why you see the message referring to the organization entity manager but datasource init ran on the main datasource. That code also creates the JPA entity manager manually and yet uses spring.jpa properties. I don't think that those properties are applied so I doubt Hibernate is creating anyting. So data.sql fails simply because the main entity manager hasn't ran yet and I don't think it creates the schema anyway.

There are a lot of moving parts in your sample. Would you have some time to reconsider the points I've mentioned and simplify it? It would be nicer if we would be able to match the entity manager that belongs to the datasource that's initialized so that's a totally valid point but it would only improve the error message.

Comment From: mrifni

Thank you for the reply. I was able to make this sample project work by renaming PrimaryDataConfig.kt to APrimaryDataConfig.kt. In that case spring boot initialised the APrimaryDataConfig.kt first before the OrganisationServiceDataConfig.kt. This is because of alphabetic order i guess.

My questions now are why data.sql isnt run after creating all the datasources otherwise its prone to fail. And why @Primary datasource class isnt initilazed first before other datasources but rather initialised based on alphabetic class name order. Also is there anyway to specify data.sql per datasource ? otherwise how to know on which datasource is data.sql executing on.

thank you again.

Comment From: snicoll

Thanks for the feedback. So that confirms that if the proper entity manager is invoked, then your application runs as expected. We'll track this issue here.

DataSource initialization in Spring Boot is a feature we need to revisit. If you are using several datasources, you shouldn't really rely on anything from spring.datasource. I'd rather configure initialization directly using ResourceDatabasePopulator. As you rely on the DataSource and Hibernate to be configured, you could have a bean that injects the datasource and the entity manager and apply the initialization. Or a BeanFactoryProcessor that does the same thing as our initialization (less generic of course as you know the bean names in your specific case).

Having said all that, the use case of letting JPA create the schema and then initializing it is the most complex of all and you could reduce significantly your setup by using a schema management tool like liquibase or flyway (or the ResourceDatabasePopulator but managing the schema and the data).

As for your other questions, let's not turn that this issue into a support request. Please ask your questions on StackOverflow or Gitter.

Comment From: wilkinsona

This has been addressed in 2.5 with the rewrite of DataSource initialization. A DataSourceScriptDatabaseInitializer is now auto-configured for the context's primary (or only) DataSource. Additional DataSources can be initialized by defining additional DataSourceScriptDatabaseInitializer beans.

The problem reported here is fairly complex and something of an edge case. Rather than destabilising things in a 2.3.x or 2.4.x maintenance release, I think we should close this in favour of the improvements that are coming in 2.5. Flagging for team attention to see what everyone else thinks.