New SQLDataSource Finalizer Thread behavior

[jay.l.fisher]

I'm running the latest nightly SGWT EE build from 1/17 and I've started to notice errors in my Eclipse console like this.

javax.naming.NoInitialContextException: Need to specify class name in environment or system property, or as an applet parameter, or in an application resource file:  java.naming.factory.initial
	at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:645)
	at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:288)
	at javax.naming.InitialContext.getURLOrDefaultInitCtx(InitialContext.java:325)
	at javax.naming.InitialContext.lookup(InitialContext.java:392)
	at com.isomorphic.sql.PoolableSQLConnectionFactory.makeUnpooledObject(PoolableSQLConnectionFactory.java:237)
	at com.isomorphic.sql.PoolableSQLConnectionFactory.makeObject(PoolableSQLConnectionFactory.java:315)
	at com.isomorphic.pool.PoolManager.borrowObject(PoolManager.java:76)
	at com.isomorphic.sql.SQLConnectionManager.getConnection(SQLConnectionManager.java:150)
	at com.isomorphic.sql.SQLDriver.implementerClassForDB(SQLDriver.java:222)
	at com.isomorphic.sql.SQLDriver.instance(SQLDriver.java:184)
	at com.isomorphic.sql.SQLDataSource.init(SQLDataSource.java:160)
	at com.isomorphic.datasource.BasicDataSource.fromConfig(BasicDataSource.java:165)
	at com.isomorphic.datasource.DataSource.fromConfig(DataSource.java:337)
	at com.isomorphic.datasource.FileSystemDSRepo.loadDS(FileSystemDSRepo.java:110)
	at com.isomorphic.datasource.DataSource.forName(DataSource.java:156)
	at com.isomorphic.datasource.DataSource.forName(DataSource.java:148)
	at com.isomorphic.datasource.DataSource.forName(DataSource.java:143)
	at com.isomorphic.datasource.PoolableDataSourceFactory.makeUnpooledObject(PoolableDataSourceFactory.java:95)
	at com.isomorphic.datasource.PoolableDataSourceFactory.makeObject(PoolableDataSourceFactory.java:102)
	at com.isomorphic.pool.PoolManager.borrowObject(PoolManager.java:82)
	at com.isomorphic.datasource.DataSourceManager.getDataSource(DataSourceManager.java:62)
	at com.isomorphic.datasource.DSRequest.getDataSource(DSRequest.java:1279)
	at com.isomorphic.sql.SQLTransaction.getConnection(SQLTransaction.java:141)
	at com.isomorphic.sql.SQLDataSource.freeResources(SQLDataSource.java:2280)
	at com.isomorphic.datasource.DSRequest.freeResources(DSRequest.java:2771)
	at com.isomorphic.datasource.DSRequest.finalize(DSRequest.java:1758)
	at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
	at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
	at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)
=== 2011-01-18 01:20:26,846 [izer] WARN  SQLDataSource - Exception while ending transaction connection
java.sql.SQLException: javax.naming.NoInitialContextException: Need to specify class name in environment or system property, or as an applet parameter, or in an application resource file:  java.naming.factory.initial
	at com.isomorphic.sql.SQLConnectionManager.getConnection(SQLConnectionManager.java:159)
	at com.isomorphic.sql.SQLDriver.implementerClassForDB(SQLDriver.java:222)
	at com.isomorphic.sql.SQLDriver.instance(SQLDriver.java:184)
	at com.isomorphic.sql.SQLDataSource.init(SQLDataSource.java:160)
	at com.isomorphic.datasource.BasicDataSource.fromConfig(BasicDataSource.java:165)
	at com.isomorphic.datasource.DataSource.fromConfig(DataSource.java:337)
	at com.isomorphic.datasource.FileSystemDSRepo.loadDS(FileSystemDSRepo.java:110)
	at com.isomorphic.datasource.DataSource.forName(DataSource.java:156)
	at com.isomorphic.datasource.DataSource.forName(DataSource.java:148)
	at com.isomorphic.datasource.DataSource.forName(DataSource.java:143)
	at com.isomorphic.datasource.PoolableDataSourceFactory.makeUnpooledObject(PoolableDataSourceFactory.java:95)
	at com.isomorphic.datasource.PoolableDataSourceFactory.makeObject(PoolableDataSourceFactory.java:102)
	at com.isomorphic.pool.PoolManager.borrowObject(PoolManager.java:82)
	at com.isomorphic.datasource.DataSourceManager.getDataSource(DataSourceManager.java:62)
	at com.isomorphic.datasource.DSRequest.getDataSource(DSRequest.java:1279)
	at com.isomorphic.sql.SQLTransaction.getConnection(SQLTransaction.java:141)
	at com.isomorphic.sql.SQLDataSource.freeResources(SQLDataSource.java:2280)
	at com.isomorphic.datasource.DSRequest.freeResources(DSRequest.java:2771)
	at com.isomorphic.datasource.DSRequest.finalize(DSRequest.java:1758)
	at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
	at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
	at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)

We're using a DynamicDataSourceGenerator. One of the things our dynamic ds generator does is set the dbName for the data source based on a choice the user makes at login (we're using Spring security). This was, and is, working fine. The exception isn't harming the way the app works, as it seems to happen during some sort of new cleanup process.

The root cause of the exception is that when SQLDataSource.freeResources() ends up calling our dynamic ds generator, it gets a null return from Spring's SecurityContextHolder.getContext().getAuthentication() method. I don't know why the ds generator is being called during cleanup, but the user has already logged in so I'm also not sure why getAuthentication() is returning null. But it only happens on this FinalizerThread. The actual data source operations work without error, but the call to freeResources() fails.

I know the root problem is with Spring, but if can you explain what is going on with this new FinalizerThread we can look for the right solution. Is it a separate child thread that gets spawned to do the cleanup? If so, when does that happen?

[Isomorphic]

This call is taking place because the DSRequest's finalize() method is invoking standard resource-freeing code, as a safety measure. This has recently changed to check to see if there is still an open transactional database connection associated with the processing queue (in any normal case, there won't be, because this cleanup will already have taken place - the finalizer is only intended as a catch-all in an error scenario).

We will add a flag to the resource cleanup so that the finalizer does not attempt to perform cleanup that has already been done.

[Isomorphic]

This has now been done