Database not initialized in production environment using 7.1.2 with optional REST add-on

dkurz · December 6, 2019, 4:54pm

I’m seeking further information regarding when the CUBA platform performs database sanity checks. Specifically, when a schema inspection is performed – and not a connectivity check. I have a project developed using platform 7.1.2 which I deploy as a single WAR to Tomcat 9.0.27-openjdk-1.8.0_222 on Jelastic. I’m using PostgreSQL 11.5 in the same environment which contains a blank database used by my app. When I deploy and start Tomcat all is good until the scheduler starts and Spring attempts to satisfy service dependencies, one of which is a CUBA Configuration instance. And this is where things blow-up. The configuration service makes a call to the database, which is still blank. It seems since the REST services were extracted from the core and placed into a separate optional add-on this problem now exists. I have a Spring helper component that depends on the CUBA configuration service and is injected into a middleware service used by a custom REST service endpoint. From what I can ascertain Spring is initializing the helper component prior to CUBA performing its DB schema inspections.

I’ve invested a considerable amount of time tracing the code and haven’t pinpointed the exact point in the start-up process where a schema check is performed. More importantly, can I programmatically control the init process to ensure all environment checks are completed before my REST services are initialized. Below is a portion of my app log which chronicles the events I mentioned above. Any help or guidance is appreciated.

2019-12-06 03:54:45.216 INFO [main] com.haulmont.cuba.core.sys.AppComponents - Using app components: [com.haulmont.cuba, org.strangeway.responsive, com.haulmont.addon.grapesjs, de.balvi.cuba.declarativecontrollers, com.haulmont.charts, com.haulmont.fts, com.haulmont.reports, com.haulmont.addon.admintools, com.haulmont.addon.tour, com.haulmont.addon.dashboard, com.haulmont.addon.dnd, com.haulmont.addon.globalevents, com.haulmont.addon.search, com.haulmont.addon.restapi, com.haulmont.addon.emailtemplates, de.diedavids.cuba.entitysoftreference, de.diedavids.cuba.taggable, de.diedavids.cuba.wizard, de.diedavids.cuba.scheduledreports, de.diedavids.cuba.dataimport]
2019-12-06 03:54:45.316 INFO [main] com.haulmont.cuba.core.sys.AbstractWebAppContextLoader - Loading app properties from classpath:com/codefusion360/sandstorm/app.properties
2019-12-06 03:54:45.322 INFO [main] com.haulmont.cuba.core.sys.AbstractWebAppContextLoader - Loading app properties from /WEB-INF/local.app.properties
2019-12-06 03:54:45.619 INFO [main] com.haulmont.cuba.core.sys.AppContextLoader - DbmsType of the main database is set to postgres
2019-12-06 03:54:45.696 INFO [main] com.haulmont.cuba.core.sys.environmentcheck.DataStoresCheck - Checking connection to data store _MAIN_
2019-12-06 03:54:46.065 INFO [main] com.haulmont.cuba.core.sys.environmentcheck.EnvironmentChecksRunner - Environment checks on core module completed successfully
2019-12-06 03:54:47.514 INFO [main] com.haulmont.cuba.core.sys.persistence.MappingFileCreator - Creating file /opt/tomcat/storm-core/work/orm.xml
2019-12-06 03:54:47.584 INFO [main] com.haulmont.cuba.core.sys.persistence.PersistenceConfigProcessor - Creating file /opt/tomcat/storm-core/work/persistence.xml
2019-12-06 03:55:09.777 INFO [main] com.haulmont.cuba.core.sys.CubaThreadPoolTaskScheduler - Initializing ExecutorService 'scheduler'
2019-12-06 03:55:15.459 INFO [main] com.haulmont.cuba.core.sys.CubaThreadPoolTaskScheduler - Initializing ExecutorService 'restapi_scheduler'
2019-12-06 03:55:16.457 INFO [main] com.haulmont.cuba.core.app.ConfigStorage - Loading DB-stored app properties cache
2019-12-06 03:55:16.500 WARN [main] com.haulmont.cuba.core.sys.singleapp.SingleAppCoreContextLoader$1 - Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'storm_PaymentProcessingService': Unsatisfied dependency expressed through field 'authorizeDotNetHelper'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'authorizeDotNetHelper': Invocation of init method failed; nested exception is java.lang.RuntimeException: Error loading DB-stored app properties cache
2019-12-06 03:55:16.501 INFO [main] com.haulmont.cuba.core.sys.CubaThreadPoolTaskScheduler - Shutting down ExecutorService 'restapi_scheduler'
2019-12-06 03:55:16.507 INFO [main] com.haulmont.cuba.core.sys.CubaThreadPoolTaskScheduler - Shutting down ExecutorService 'scheduler

albudarov · December 9, 2019, 6:56am

Hi,

I am sorry but the quoted log message contradicts to your description of the problem.
The log message tells that Spring context initialization has failed. It has failed because the bean “authorizeDotNetHelper” was trying to access DB-stored Configuration properties during its initialization. And it is not possible and you should not do that.

If you need to run some initialization of your beans that requires access to the database - you should use one of AppContextInitializedEvent or AppContextStartedEvent events.
But not before! Not in bean constructor, neither in init() or @PostConstruct methods access to DB or other Spring beans it not allowed, because the application has not been initialized yet.

https://doc.cuba-platform.com/manual-7.1/app_lifecycle_events.html

dkurz · December 9, 2019, 3:36pm

Hey Alex,

Thanks for the reply. In my simplistic and cursory interpretation of the platform initialization routines, I was expecting the database initialization or update routines to run before Spring bean init. When developing from Studio the app always loaded properly since Gradle handled the DB init. Your recommendation makes perfect sense, and I’m a bit aggravated with myself for not remembering to put dependency init code within one of the lifecycle event handlers. Thanks again!