I'm seeing the below using WAS 6 and SqlServer 2000, with IBM's embedded SqlServer driver used for a container managed DataSource.

I looked at the source and here's where it's blowing up:

private void closePreparedStatement(PreparedStatement ps) throws SQLException {
try {
log.trace("closing statement");
ps.close(); <--- This is causing the NullPointer

What's odd is that my code works just fine when I don't use this as a container managed datasource, instead configuring it using DriverManager (through Spring).

Lots of googling and trial-and-error, but I'm stumped.

Any ideas?

Thanks!

Hibernate version:
3.0 (also just tried with Hibernate 3.1rc3)

Full stack trace of any exception that occurs:
[11/28/05 20:42:28:922 CST] 00000036 ServletWrappe E SRVE0068E: Could not invoke the service() method on servlet /LoggingTest.jsp. Exception thrown : java.lang.NullPointerException
at org.hibernate.jdbc.AbstractBatcher.closePreparedStatement(AbstractBatcher.java:471)
at org.hibernate.jdbc.AbstractBatcher.closeStatement(AbstractBatcher.java:218)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:1980)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2404)
at org.hibernate.action.EntityIdentityInsertAction.execute(EntityIdentityInsertAction.java:37)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:269)
at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:167)
at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:101)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:186)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:175)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.performSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:98)
at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70)
at org.hibernate.impl.SessionImpl.fireSaveOrUpdate(SessionImpl.java:502)
at org.hibernate.impl.SessionImpl.saveOrUpdate(SessionImpl.java:496)
at org.hibernate.impl.SessionImpl.saveOrUpdate(SessionImpl.java:492)
at org.springframework.orm.hibernate3.HibernateTemplate$18.doInHibernate(HibernateTemplate.java:673)
at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:358)
at org.springframework.orm.hibernate3.HibernateTemplate.saveOrUpdate(HibernateTemplate.java:670)


Name and version of the database you are using:
Microsoft SQL Server, version: Microsoft SQL Server 2000 - 8.00.760 (Intel X86)
Dec 17 2002 14:22:05
Copyright (c) 1988-2003 Microsoft Corporation
Enterprise Edition on Windows NT 5.0 (Build 2195: Service Pack 4)

The generated SQL (show_sql=true):
Hibernate: insert into EIVR.DBO.IVR_CALL (DNIS, ANI, CALLER_AUTH_ID, CALLER_LANGUAGE_PREFERENCE, CALL_START_TIME, CALL_END_TIME, BROWSER_IP

Debug level Hibernate log excerpt:
[11/28/05 20:42:27:610 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings JDBC driver: SQLServer, version: 3.40.51 (012743.007224.008724)
[11/28/05 20:42:27:671 CST] 00000036 Dialect I org.hibernate.dialect.Dialect <init> Using dialect: org.hibernate.dialect.SQLServerDialect
[11/28/05 20:42:27:681 CST] 00000036 TransactionFa I org.hibernate.transaction.TransactionFactoryFactory buildTransactionFactory Using default transaction strategy (direct JDBC transactions)
[11/28/05 20:42:27:681 CST] 00000036 TransactionMa I org.hibernate.transaction.TransactionManagerLookupFactory getTransactionManagerLookup No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
[11/28/05 20:42:27:741 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Automatic flush during beforeCompletion(): disabled
[11/28/05 20:42:27:741 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Automatic session close at end of transaction: disabled
[11/28/05 20:42:27:741 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Scrollable result sets: enabled
[11/28/05 20:42:27:751 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings JDBC3 getGeneratedKeys(): enabled
[11/28/05 20:42:27:811 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Connection release mode: auto
[11/28/05 20:42:27:811 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Default schema: DBO
[11/28/05 20:42:27:821 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Default catalog: EIVR
[11/28/05 20:42:27:871 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Default batch fetch size: 1
[11/28/05 20:42:27:881 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Generate SQL with comments: disabled
[11/28/05 20:42:27:881 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Order SQL updates by primary key: disabled
[11/28/05 20:42:27:881 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory createQueryTranslatorFactory Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
[11/28/05 20:42:27:941 CST] 00000036 ASTQueryTrans I org.hibernate.hql.ast.ASTQueryTranslatorFactory <init> Using ASTQueryTranslatorFactory
[11/28/05 20:42:27:941 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Query language substitutions: {}
[11/28/05 20:42:27:951 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Second-level cache: enabled
[11/28/05 20:42:28:001 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Query cache: disabled
[11/28/05 20:42:28:011 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory createCacheProvider Cache provider: org.hibernate.cache.EhCacheProvider
[11/28/05 20:42:28:011 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Optimize cache for minimal puts: disabled
[11/28/05 20:42:28:021 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Structured second-level cache entries: disabled
[11/28/05 20:42:28:091 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Echoing all SQL to stdout
[11/28/05 20:42:28:091 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Statistics: disabled
[11/28/05 20:42:28:101 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Deleted entity synthetic identifier rollback: disabled
[11/28/05 20:42:28:161 CST] 00000036 SettingsFacto I org.hibernate.cfg.SettingsFactory buildSettings Default entity-mode: POJO
[11/28/05 20:42:28:171 CST] 00000036 SessionFactor I org.hibernate.impl.SessionFactoryImpl <init> building session factory
[11/28/05 20:42:28:372 CST] 00000036 SessionFactor I org.hibernate.impl.SessionFactoryObjectFactory addInstance Not binding factory to JNDI, no JNDI name configured
[11/28/05 20:42:28:452 CST] 00000036 SessionFactor I org.hibernate.impl.SessionFactoryImpl checkNamedQueries Checking 0 named HQL queries
[11/28/05 20:42:28:592 CST] 00000036 SessionFactor I org.hibernate.impl.SessionFactoryImpl checkNamedQueries Checking 0 named SQL queries
[11/28/05 20:42:28:602 CST] 00000036 HibernateTran I org.springframework.orm.hibernate3.HibernateTransactionManager afterPropertiesSet Using DataSource [com.hcsc.eas.framework.datasource.debug.DebugDataSource@59825a76] of Hibernate SessionFactory for HibernateTransactionManager
[11/28/05 20:42:28:852 CST] 00000036 SystemOut O Hibernate: insert into EIVR.DBO.IVR_CALL (DNIS, ANI, CALLER_AUTH_ID, CALLER_LANGUAGE_PREFERENCE, CALL_START_TIME, CALL_END_TIME, BROWSER_IP_ADDRESS) values (?, ?, ?, ?, ?, ?, ?)
[11/28/05 20:42:28:852 CST] 00000036 StringType I org.hibernate.type.NullableType nullSafeSet could not bind value '87576576' to parameter: 1
[11/28/05 20:42:28:852 CST] 00000036 StringType I org.hibernate.type.NullableType nullSafeSet could not bind value '123' to parameter: 2
[11/28/05 20:42:28:862 CST] 00000036 StringType I org.hibernate.type.NullableType nullSafeSet could not bind value 'null' to parameter: 3
[11/28/05 20:42:28:872 CST] 00000036 StringType I org.hibernate.type.NullableType nullSafeSet could not bind value 'null' to parameter: 4
[11/28/05 20:42:28:912 CST] 00000036 TimestampType I org.hibernate.type.NullableType nullSafeSet could not bind value '2005-11-28 20:42:28' to parameter: 5

Looks to me like line 216 of AbstractBatcher:


Should probably be:



Do you think you could download the sources and try it?

Thanks for the reply Joshua. I'll do that this morning and see what happens. I was wondering if this was an indication of a problem with IBM's embedded SqlServer datasource. But if the straight-forward fixe works I'll be very happy at this point...

Probably. I can't see how the NPE would happen otherwise. UTSL and find out for yourself. ;)

ha. I Like the acronym.

I made the change you suggested, and the problem shifted elsewhere... NullPointer a little further down the line. Made a change for that and another appeared. So I think it's pretty clear Hibernate isn't broken, it's either the driver or how I'm using it. If I figure something interesting out (latter case doesn't qualify) I'll post about it.

Very good. Thanks!