NullPointerException / race conditions in DataSourceSupport and JavaSettingsImpl

dev
1

Was about to file this on Jira but it says to run it here first.

Version is 5.4.3.2.

We have code like the following:

array function getThings() { ... }
function workThings() {
    getThings().map(closure = (v) => { runQueriesAndEtc(v); }, parallel = true);
}

The above generally works, but throws NullPointerExceptions maybe once or twice a week.

It looks like there are races on

  • lucee.runtime.listener.JavaSettingsImpl.getBundlesTranslated(JavaSettingsImpl.java:98)
  • lucee.runtime.db.DataSourceSupport.initialize(DataSourceSupport.java:164)

Where multiple threads race to initialize a data source. I’ve included images of a debug session, intending to show the following:

  • Thread pool-11-thread-7 is mutating JavaSettingsImpl@94
  • Thread pool-11-thread-7 is mutating ApplicationDataSource@116
  • Thread pool-11-thread-8 is mutating JavaSettingsImpl@94 (same as pool-11-thread-7)
  • Thread pool-11-thread-8 is mutating ApplicationDataSource@116 (same as pool-11-thread-7)

Getting a consistent repro is a little difficult, but placing a “synthetic gc pause” (just a random Thread.sleep of anywhere between 0-20ms) here:

// JavaSettingsImpl:98
if (bundlesTranslated != null && (randomPauseThenReturnTrue()) && bundlesTranslated.isEmpty()) bundlesTranslated = null;

can suss it out.

I slapped double checked locks on both sites and that seems to patch it up; but maybe there is a broader architectural solution I am overlooking.

A full stack trace looks like:

"ERROR","XNIO-1 task-14","09/17/2023","07:25:14","","java.lang.NullPointerException;lucee.runtime.exp.NativeException: java.lang.NullPointerException
    at lucee.runtime.listener.JavaSettingsImpl.getBundlesTranslated(JavaSettingsImpl.java:98)
    at lucee.runtime.listener.JavaSettingsImpl.getBundles(JavaSettingsImpl.java:255)
    at lucee.transformer.library.ClassDefinitionImpl.getClazz(ClassDefinitionImpl.java:117)
    at lucee.runtime.db.DataSourceSupport._initializeDriver(DataSourceSupport.java:172)
    at lucee.runtime.db.DataSourceSupport.initialize(DataSourceSupport.java:164)
    at lucee.runtime.db.DataSourceSupport.getConnection(DataSourceSupport.java:103)
    at lucee.runtime.db.DatasourceConnectionPool.loadDatasourceConnection(DatasourceConnectionPool.java:158)
    at lucee.runtime.db.DatasourceConnectionPool.getDatasourceConnection(DatasourceConnectionPool.java:121)
    at lucee.runtime.db.DatasourceManagerImpl.getConnection(DatasourceManagerImpl.java:82)
    at lucee.runtime.tag.Query.executeDatasoure(Query.java:1120)
    at lucee.runtime.tag.Query._doEndTag(Query.java:700)
    at lucee.runtime.tag.Query.doEndTag(Query.java:566)
    at lucee.runtime.functions.query.QueryExecute.call(QueryExecute.java:86)
    at models.grammars.basegrammar_cfc$cf.udfCall1(/qb/models/Grammars/BaseGrammar.cfc:116)
    at models.grammars.basegrammar_cfc$cf.udfCall(/qb/models/Grammars/BaseGrammar.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:213)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:699)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:586)
    at lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1952)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:866)
    at lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1794)
    at models.query.querybuilder_cfc$cf.udfCallj(/qb/models/Query/QueryBuilder.cfc:3559)
    at models.query.querybuilder_cfc$cf.udfCall(/qb/models/Query/QueryBuilder.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:213)
    at lucee.runtime.type.scope.UndefinedImpl.callWithNamedValues(UndefinedImpl.java:804)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:866)
    at lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1794)
    at models.query.querybuilder_cfc$cf.udfCallj(/qb/models/Query/QueryBuilder.cfc:3512)
    at models.query.querybuilder_cfc$cf.udfCall(/qb/models/Query/QueryBuilder.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:213)
    at lucee.runtime.type.scope.UndefinedImpl.callWithNamedValues(UndefinedImpl.java:804)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:866)
    at lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1794)
    at models.query.querybuilder_cfc$cf.udfCallh(/qb/models/Query/QueryBuilder.cfc:3264)
    at models.query.querybuilder_cfc$cf.udfCall(/qb/models/Query/QueryBuilder.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:698)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:586)
    at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1933)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
    at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1775)
    at models.quickbuilder_cfc$cf.udfCall2(/quick/models/QuickBuilder.cfc:239)
    at models.quickbuilder_cfc$cf.udfCall(/quick/models/QuickBuilder.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223)
    at lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:786)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
    at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1775)
    at models.quickbuilder_cfc$cf.udfCall2(/quick/models/QuickBuilder.cfc:264)
    at models.quickbuilder_cfc$cf.udfCall(/quick/models/QuickBuilder.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:698)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:586)
    at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1933)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
    at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1775)
    at models.relationships.hasmany_cfc$cf.udfCall(/quick/models/Relationships/HasMany.cfc:26)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223)
    at lucee.runtime.ComponentScopeShadow.call(ComponentScopeShadow.java:313)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
    at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1775)
    at models.relationships.baserelationship_cfc$cf.udfCall1(/quick/models/Relationships/BaseRelationship.cfc:187)
    at models.relationships.baserelationship_cfc$cf.udfCall(/quick/models/Relationships/BaseRelationship.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:698)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:586)
    at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1933)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
    at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1775)
    at models.baseentity_cfc$cf.udfCallb(/quick/models/BaseEntity.cfc:2229)
    at models.baseentity_cfc$cf.udfCall(/quick/models/BaseEntity.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223)
    at lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:786)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787)
    at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1775)
    at models.baseentity_cfc$cf.udfCallb(/quick/models/BaseEntity.cfc:2112)
    at models.baseentity_cfc$cf.udfCall(/quick/models/BaseEntity.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:698)
    at lucee.runtime.ComponentImpl.onMissingMethod(ComponentImpl.java:625)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:588)
    at lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1952)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:900)
    at lucee.runtime.functions.dynamicEvaluation.Invoke.call(Invoke.java:49)
    at lucee.runtime.functions.dynamicEvaluation.Invoke.call(Invoke.java:36)
    at interceptors.mementifier_cfc$cf.udfCall1(/mementifier/interceptors/Mementifier.cfc:275)
    at interceptors.mementifier_cfc$cf.udfCall(/mementifier/interceptors/Mementifier.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:213)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:699)
    at lucee.runtime.ComponentImpl._call(ComponentImpl.java:586)
    at lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1952)
    at lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:866)
    at lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1794)
    at api.modules_app.v1.handlers.game_cfc$cf.udfCall1(/modules_app/api/modules_app/v1/handlers/game.cfc:262)
    at api.modules_app.v1.handlers.game_cfc$cf.udfCall(/modules_app/api/modules_app/v1/handlers/game.cfc)
    at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112)
    at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350)
    at lucee.runtime.type.UDFImpl.call(UDFImpl.java:218)
    at lucee.runtime.type.EnvUDF.call(EnvUDF.java:109)
    at lucee.runtime.concurrency.UDFCaller2.call(UDFCaller2.java:84)
    at lucee.runtime.concurrency.UDFCaller2.call(UDFCaller2.java:38)
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.base/java.lang.Thread.run(Unknown Source)

composite
composite3585×1349 1.01 MB

2

Given that Lucee has a single configuration, you need to approach it as such

whilst we can look into the NPE, you’ll possibly need to either batch up / lock your updates or re consider your approach

3

Does this mean that queryExecute from within map(parallel=true) is not supported? The repro can be as simple as:

[1,2].map(closure = () => queryExecute("select 1"), parallel=true)

edit:typo

4

oh, so it’s happening with the same datasource definition?

5

Yes. We have observed threads pool-11-thread-7 and thread pool-11-thread-8 concurrently initializing the driver field of the same ApplicationDataSource (ApplicationDataSource@116 in the images above).

6

fixed [LDEV-4701] - Lucee

7

@David_Rogers1 does the latest snapshot 5.4.4.2 resolve the issue for you?

8

Just glancing at the changeset, it probably does. We haven’t rolled it out yet though.