not-null property references a null or transient value

dynoweb · **Joined:** Wed May 17, 2006 6:06 pm **Posts:** 8

I'm trying to get an XML doc of the records. When the code hits the tx.commit(); line, I get the attached exception. The XML file hibernateQuery.xml contains the expected records.

The database has the pager field set as NOT NULL default "" (Empty String). Most of the records are set to the empty string.

What am I doing wrong?

Hibernate version:
Hibernate 3.1.2

Mapping documents:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping>

<class name="VoicemailUsers"
table="VOICEMAIL_USERS"
node="voiceMailUser">

<id name="uniqueid"
column="UNIQUEID"
node="uniqueid">
<generator class="native"/>
</id>

<property name="customer_id"/>
<property name="context"/>
<property name="mailbox"/>
<property name="password"/>
<property name="fullname"/>
<property name="email"/>

<property name="pager"
not-null="true"/>

<property name="stamp"
column="STAMP"
type="date"
not-null="true"/>
</class>

</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():
Session dom4jSession = session.getSession(EntityMode.DOM4J);
Transaction tx = session.beginTransaction();
List results = dom4jSession.createQuery("from VoicemailUsers").list();
for (int i=0; i< results.size(); i++) {
Element user = (Element) results.get(i);
data.add(user);
}
writeDocToFile(document, "\\hibernateQuery.xml");
tx.commit();
session.clear();

Full stack trace of any exception that occurs:
org.hibernate.PropertyValueException: not-null property references a null or transient value: com.emergent_netsolutions.pbx.VoicemailUsers.pager
at org.hibernate.engine.Nullability.checkNullability(Nullability.java:72)
at org.hibernate.event.def.DefaultFlushEntityEventListener.scheduleUpdate(DefaultFlushEntityEventListener.java:256)
at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:114)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:195)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1009)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:361)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at com.emergent_netsolutions.pbx.VoicemailUsersManager.listVoiceMailUsers(VoicemailUsersManager.java:94)
at com.emergent_netsolutions.pbx.VoicemailUsersManager.main(VoicemailUsersManager.java:34)
Exception in thread "main"
Name and version of the database you are using:
MySQL version 5.0.21

The generated SQL (show_sql=true):
Hibernate:
select
voicemailu0_.UNIQUEID as UNIQUEID0_,
voicemailu0_.customer_id as customer2_0_,
voicemailu0_.context as context0_,
voicemailu0_.mailbox as mailbox0_,
voicemailu0_.password as password0_,
voicemailu0_.fullname as fullname0_,
voicemailu0_.email as email0_,
voicemailu0_.pager as pager0_,
voicemailu0_.STAMP as STAMP0_
from
VOICEMAIL_USERS voicemailu0_

Debug level Hibernate log excerpt:

POJO
import java.util.Date;

public class VoicemailUsers {

private int uniqueid;
private int customer_id;
.......
private String pager = "";
private Date stamp;

public int getCustomer_id() {

return customer_id;
}

public void setCustomer_id(int customer_id) {

this.customer_id = customer_id;
}

public String getPager() {

return pager;
}

public void setPager(String pager) {

this.pager = pager;
//this.pager = pager == null ? "" : pager;
}

public Date getStamp() {

return stamp;
}

public void setStamp(Date stamp) {

this.stamp = stamp;
}

public int getUniqueid() {

return uniqueid;
}

public void setUniqueid(int uniqueid) {

this.uniqueid = uniqueid;
}

}

tenwit · **Joined:** Thu Dec 23, 2004 9:08 pm **Posts:** 2008

Have you verified that there are no rows in the DB with null pager values? That can happen if you added the not null restriction when there were nulls already in the DB: most DBMSs allow you to skip the check for existing rows.

If you turn on parameter tracing, you can see where the null is going into the DB (and/or coming out of it). Add "log4j.logger.org.hibernate.type=DEBUG" to your log4j.properties file.

dynoweb · **Joined:** Wed May 17, 2006 6:06 pm **Posts:** 8

The database does not allow nulls for the PAGER field and has a default of an Empty String.

Here's my dump of the console with the log4j change. I wasn't able to find any different information in the log.

Code:

08:41:09,233  INFO Environment:479 - Hibernate 3.1.2
08:41:09,249  INFO Environment:509 - hibernate.properties not found
08:41:09,249  INFO Environment:525 - using CGLIB reflection optimizer
08:41:09,249  INFO Environment:555 - using JDK 1.4 java.sql.Timestamp handling
08:41:09,327  INFO Configuration:1308 - configuring from resource: /hibernate.cfg.xml
08:41:09,327  INFO Configuration:1285 - Configuration resource: /hibernate.cfg.xml
08:41:09,389  INFO Configuration:469 - Reading mappings from resource: com/emergent_netsolutions/pbx/VoicemailUsers.hbm.xml
08:41:09,514  INFO HbmBinder:309 - Mapping class: com.emergent_netsolutions.pbx.VoicemailUsers -> VOICEMAIL_USERS
08:41:09,546  INFO Configuration:1419 - Configured SessionFactory: null
08:41:09,624  INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
08:41:09,624  INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 1
08:41:09,624  INFO DriverManagerConnectionProvider:45 - autocommit mode: false
08:41:09,639  INFO DriverManagerConnectionProvider:80 - using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost/emergentpbx?zeroDateTimeBehavior=convertToNull
08:41:09,639  INFO DriverManagerConnectionProvider:86 - connection properties: {user=root, password=****}
08:41:09,952  INFO SettingsFactory:77 - RDBMS: MySQL, version: 5.0.20-nt
08:41:09,952  INFO SettingsFactory:78 - JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.10 ( $Date: 2005/05/19 15:52:23 $, $Revision: 1.1.2.2 $ )
08:41:09,983  INFO Dialect:103 - Using dialect: org.hibernate.dialect.MySQLDialect
08:41:09,999  INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions)
08:41:09,999  INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
08:41:09,999  INFO SettingsFactory:125 - Automatic flush during beforeCompletion(): disabled
08:41:09,999  INFO SettingsFactory:129 - Automatic session close at end of transaction: disabled
08:41:09,999  INFO SettingsFactory:136 - JDBC batch size: 15
08:41:09,999  INFO SettingsFactory:139 - JDBC batch updates for versioned data: disabled
08:41:09,999  INFO SettingsFactory:144 - Scrollable result sets: enabled
08:41:09,999  INFO SettingsFactory:152 - JDBC3 getGeneratedKeys(): enabled
08:41:10,014  INFO SettingsFactory:160 - Connection release mode: auto
08:41:10,014  INFO SettingsFactory:184 - Maximum outer join fetch depth: 2
08:41:10,014  INFO SettingsFactory:187 - Default batch fetch size: 1
08:41:10,014  INFO SettingsFactory:191 - Generate SQL with comments: disabled
08:41:10,014  INFO SettingsFactory:195 - Order SQL updates by primary key: disabled
08:41:10,014  INFO SettingsFactory:338 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
08:41:10,014  INFO ASTQueryTranslatorFactory:24 - Using ASTQueryTranslatorFactory
08:41:10,014  INFO SettingsFactory:203 - Query language substitutions: {}
08:41:10,014  INFO SettingsFactory:209 - Second-level cache: enabled
08:41:10,014  INFO SettingsFactory:213 - Query cache: disabled
08:41:10,014  INFO SettingsFactory:325 - Cache provider: org.hibernate.cache.NoCacheProvider
08:41:10,014  INFO SettingsFactory:228 - Optimize cache for minimal puts: disabled
08:41:10,014  INFO SettingsFactory:237 - Structured second-level cache entries: disabled
08:41:10,030  INFO SettingsFactory:257 - Echoing all SQL to stdout
08:41:10,030  INFO SettingsFactory:264 - Statistics: disabled
08:41:10,030  INFO SettingsFactory:268 - Deleted entity synthetic identifier rollback: disabled
08:41:10,030  INFO SettingsFactory:283 - Default entity-mode: pojo
08:41:10,061  INFO SessionFactoryImpl:153 - building session factory
08:41:10,467  INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
Hibernate: 
    select
        voicemailu0_.UNIQUEID as UNIQUEID0_,
        voicemailu0_.customer_id as customer2_0_,
        voicemailu0_.context as context0_,
        voicemailu0_.mailbox as mailbox0_,
        voicemailu0_.password as password0_,
        voicemailu0_.fullname as fullname0_,
        voicemailu0_.email as email0_,
        voicemailu0_.pager as pager0_,
        voicemailu0_.STAMP as STAMP0_ 
    from
        VOICEMAIL_USERS voicemailu0_
org.hibernate.PropertyValueException: not-null property references a null or transient value: com.emergent_netsolutions.pbx.VoicemailUsers.pager
   at org.hibernate.engine.Nullability.checkNullability(Nullability.java:72)
   at org.hibernate.event.def.DefaultFlushEntityEventListener.scheduleUpdate(DefaultFlushEntityEventListener.java:256)
   at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:114)
   at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:195)
   at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1009)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:361)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at com.emergent_netsolutions.pbx.VoicemailUsersManager.listVoiceMailUsers(VoicemailUsersManager.java:94)
   at com.emergent_netsolutions.pbx.VoicemailUsersManager.main(VoicemailUsersManager.java:34)
Exception in thread "main" 

tenwit · **Joined:** Thu Dec 23, 2004 9:08 pm **Posts:** 2008

dynoweb wrote:

The database does not allow nulls for the PAGER field and has a default of an Empty String.

That doesn't mean that there are no nulls in that field, just that you can't put any nulls into it now. You should doublecheck that there are no nulls (select count(*) from table where col is null).

dynoweb wrote:

Here's my dump of the console with the log4j change. I wasn't able to find any different information in the log.

You'll have to turn on parameter tracing too. My previous post tells you how to do that.

dynoweb · **Joined:** Wed May 17, 2006 6:06 pm **Posts:** 8

I performed the following query with no records returned

select * from voicemail_users where pager is null

This query returned all of the rows

select * from voicemail_users where pager = ''

Here's the SQL that describes the table

Code:

CREATE TABLE `voicemail_users` (                                                     
                   `uniqueid` int(11) NOT NULL auto_increment,                                        
                   `customer_id` int(11) NOT NULL default '0',                                        
                   `context` varchar(50) NOT NULL default '',                                         
                   `mailbox` varchar(20) NOT NULL default '0',                                        
                   `password` varchar(4) NOT NULL default '0',                                        
                   `fullname` varchar(50) NOT NULL default '',                                        
                   `email` varchar(50) default NULL,                                                  
                   `pager` varchar(50) NOT NULL  default '',                                                      
                   `stamp` timestamp NOT NULL default CURRENT_TIMESTAMP on update CURRENT_TIMESTAMP,  
                   PRIMARY KEY  (`uniqueid`),                                                         
                   KEY `mailbox_context` (`mailbox`,`context`)                                        
                 ) ENGINE=MyISAM DEFAULT CHARSET=latin1

Here's the dump with the extra log4j information

Code:

18:36:23,921  INFO Environment:479 - Hibernate 3.1.2
18:36:23,936  INFO Environment:509 - hibernate.properties not found
18:36:23,936  INFO Environment:525 - using CGLIB reflection optimizer
18:36:23,936  INFO Environment:555 - using JDK 1.4 java.sql.Timestamp handling
18:36:24,014  INFO Configuration:1308 - configuring from resource: /hibernate.cfg.xml
18:36:24,014  INFO Configuration:1285 - Configuration resource: /hibernate.cfg.xml
18:36:24,124  INFO Configuration:469 - Reading mappings from resource: com/emergent_netsolutions/pbx/VoicemailUsers.hbm.xml
18:36:24,233  INFO HbmBinder:309 - Mapping class: com.emergent_netsolutions.pbx.VoicemailUsers -> VOICEMAIL_USERS
18:36:24,264  INFO Configuration:1419 - Configured SessionFactory: null
18:36:24,358  INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
18:36:24,358  INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 1
18:36:24,358  INFO DriverManagerConnectionProvider:45 - autocommit mode: false
18:36:24,358  INFO DriverManagerConnectionProvider:80 - using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost/emergentpbx?zeroDateTimeBehavior=convertToNull&emptyStringsConvertToZero=false
18:36:24,358  INFO DriverManagerConnectionProvider:86 - connection properties: {user=root, password=****}
18:36:24,655  INFO SettingsFactory:77 - RDBMS: MySQL, version: 5.0.20-nt
18:36:24,671  INFO SettingsFactory:78 - JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.10 ( $Date: 2005/05/19 15:52:23 $, $Revision: 1.1.2.2 $ )
18:36:24,686  INFO Dialect:103 - Using dialect: org.hibernate.dialect.MySQLDialect
18:36:24,702  INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions)
18:36:24,702  INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
18:36:24,702  INFO SettingsFactory:125 - Automatic flush during beforeCompletion(): disabled
18:36:24,702  INFO SettingsFactory:129 - Automatic session close at end of transaction: disabled
18:36:24,702  INFO SettingsFactory:136 - JDBC batch size: 15
18:36:24,702  INFO SettingsFactory:139 - JDBC batch updates for versioned data: disabled
18:36:24,702  INFO SettingsFactory:144 - Scrollable result sets: enabled
18:36:24,702  INFO SettingsFactory:152 - JDBC3 getGeneratedKeys(): enabled
18:36:24,702  INFO SettingsFactory:160 - Connection release mode: auto
18:36:24,702  INFO SettingsFactory:184 - Maximum outer join fetch depth: 2
18:36:24,702  INFO SettingsFactory:187 - Default batch fetch size: 1
18:36:24,702  INFO SettingsFactory:191 - Generate SQL with comments: disabled
18:36:24,702  INFO SettingsFactory:195 - Order SQL updates by primary key: disabled
18:36:24,702  INFO SettingsFactory:338 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
18:36:24,717  INFO ASTQueryTranslatorFactory:24 - Using ASTQueryTranslatorFactory
18:36:24,717  INFO SettingsFactory:203 - Query language substitutions: {}
18:36:24,717  INFO SettingsFactory:209 - Second-level cache: enabled
18:36:24,717  INFO SettingsFactory:213 - Query cache: disabled
18:36:24,717  INFO SettingsFactory:325 - Cache provider: org.hibernate.cache.NoCacheProvider
18:36:24,717  INFO SettingsFactory:228 - Optimize cache for minimal puts: disabled
18:36:24,717  INFO SettingsFactory:237 - Structured second-level cache entries: disabled
18:36:24,717  INFO SettingsFactory:257 - Echoing all SQL to stdout
18:36:24,717  INFO SettingsFactory:264 - Statistics: disabled
18:36:24,733  INFO SettingsFactory:268 - Deleted entity synthetic identifier rollback: disabled
18:36:24,733  INFO SettingsFactory:283 - Default entity-mode: pojo
18:36:24,764  INFO SessionFactoryImpl:153 - building session factory
18:36:25,186  INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
18:36:25,202  INFO SessionFactoryImpl:728 - closing
18:36:25,202  INFO DriverManagerConnectionProvider:147 - cleaning up connection pool: jdbc:mysql://localhost/emergentpbx?zeroDateTimeBehavior=convertToNull&emptyStringsConvertToZero=false
Hibernate: select voicemailu0_.UNIQUEID as UNIQUEID0_, voicemailu0_.customer_id as customer2_0_, voicemailu0_.context as context0_, voicemailu0_.mailbox as mailbox0_, voicemailu0_.password as password0_, voicemailu0_.fullname as fullname0_, voicemailu0_.email as email0_, voicemailu0_.pager as pager0_, voicemailu0_.STAMP as STAMP0_ from VOICEMAIL_USERS voicemailu0_
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
18:36:25,827  WARN JDBCExceptionReporter:71 - SQL Error: 1263, SQLState: 22004
18:36:25,827 ERROR JDBCExceptionReporter:72 - Column set to default value; NULL supplied to NOT NULL column 'pager' at row 1
18:36:25,842 ERROR AbstractFlushingEventListener:299 - Could not synchronize database state with session
org.hibernate.exception.DataException: could not update: [com.emergent_netsolutions.pbx.VoicemailUsers#47]
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:75)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2222)
   at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2118)
   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2374)
   at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:84)
   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1009)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:361)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at com.emergent_netsolutions.pbx.VoicemailUsersManager.getAllVoiceMailUsers(VoicemailUsersManager.java:103)
   at com.emergent_netsolutions.pbx.VoicemailUsersManager.main(VoicemailUsersManager.java:42)
Caused by: java.sql.BatchUpdateException: Column set to default value; NULL supplied to NOT NULL column 'pager' at row 1
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:642)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.BatchingBatcher.addToBatch(BatchingBatcher.java:34)
   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2204)
   ... 13 more
org.hibernate.exception.DataException: could not update: [com.emergent_netsolutions.pbx.VoicemailUsers#47]
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:75)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2222)
   at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2118)
   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2374)
   at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:84)
   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1009)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:361)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at com.emergent_netsolutions.pbx.VoicemailUsersManager.getAllVoiceMailUsers(VoicemailUsersManager.java:103)
   at com.emergent_netsolutions.pbx.VoicemailUsersManager.main(VoicemailUsersManager.java:42)
Caused by: java.sql.BatchUpdateException: Column set to default value; NULL supplied to NOT NULL column 'pager' at row 1
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:642)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.BatchingBatcher.addToBatch(BatchingBatcher.java:34)
   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2204)
   ... 13 more
Exception in thread "main" 

Since I'm new to hibernate, I'm not sure why when I'm only trying to read, does it think that the records are dirty.

Also, if I'm not using the
Session dom4jSession = session.getSession(EntityMode.DOM4J);
and just get a standard session instead of the dom4jSession I can commit and it doesn't get this error. When I changed this to the dom4jSession, that's when this error started.

Thanks for your help.

tenwit · **Joined:** Thu Dec 23, 2004 9:08 pm **Posts:** 2008

Still no parameter tracing in that debug output.

tenwit wrote:

If you turn on parameter tracing, you can see where the null is going into the DB (and/or coming out of it). Add "log4j.logger.org.hibernate.type=DEBUG" to your log4j.properties file.

I don't know why things would change when you switched to XML storage.

You could also put a breakpoint in setPager, or maybe something like

Code:

public setPager(String pager) {
  if (pager == null) {
    System.err.println("Null pager!");
    new Exception().printStackTrace();
  }
  this.pager = pager;
}

Maybe that'll help you figure out what's going wrong.

awbacker · **Joined:** Tue May 16, 2006 4:26 pm **Posts:** 5

You could try setting the class to lazy="false", to force loading of all the columns. There was a wierd way this affected me a few weeks ago, and I think this might have been the error.

Code:

- Andrew
I'll waste one of my precious "credit" thingies on this one... Hope it's useful. Do credits discourage more people from offering suggestions?

tenwit · **Joined:** Thu Dec 23, 2004 9:08 pm **Posts:** 2008

You only use credits when starting a topic. It costs nothing to offer suggestions. That's the whole point of credits: they encourage you to give more answers, so that you can ask more questions.

I'll go ask 206 questions now :)

dynoweb · **Joined:** Wed May 17, 2006 6:06 pm **Posts:** 8

Sorry, I guess I had that log4j setting also set in another portion of the properties file. I believe this is what you were looking for. It appears that the PAGER value comes in as an Empty String and somewhere in the Hibernate codes saves it as a null so it thinks it's dirty and tries to write that back out.

I dumped some of the log records that show the same type of behavior.

Does this look like a bug in Hibernate?

Code:

09:20:49,389 INFO SettingsFactory:257 - Echoing all SQL to stdout
09:20:49,389 INFO SettingsFactory:264 - Statistics: disabled
09:20:49,389 INFO SettingsFactory:268 - Deleted entity synthetic identifier rollback: disabled
09:20:49,389 INFO SettingsFactory:283 - Default entity-mode: pojo
09:20:49,436 INFO SessionFactoryImpl:153 - building session factory
09:20:49,858 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
09:20:49,858 INFO SessionFactoryImpl:728 - closing
09:20:49,858 INFO DriverManagerConnectionProvider:147 - cleaning up connection pool: jdbc:mysql://localhost/emergentpbx?zeroDateTimeBehavior=convertToNull&emptyStringsConvertToZero=false
Hibernate: select voicemailu0_.UNIQUEID as UNIQUEID0_, voicemailu0_.customer_id as customer2_0_, voicemailu0_.context as context0_, voicemailu0_.mailbox as mailbox0_, voicemailu0_.password as password0_, voicemailu0_.fullname as fullname0_, voicemailu0_.email as email0_, voicemailu0_.pager as pager0_, voicemailu0_.STAMP as STAMP0_ from VOICEMAIL_USERS voicemailu0_
09:20:50,296 DEBUG IntegerType:123 - returning '32' as column: UNIQUEID0_
09:20:50,296 DEBUG IntegerType:123 - returning '0' as column: customer2_0_
09:20:50,311 DEBUG StringType:123 - returning 'companya' as column: context0_
09:20:50,311 DEBUG StringType:123 - returning '555359664101' as column: mailbox0_
09:20:50,311 DEBUG StringType:123 - returning '1234' as column: password0_
09:20:50,311 DEBUG StringType:123 - returning 'Asterisk Test' as column: fullname0_
09:20:50,311 DEBUG StringType:123 - returning '[email protected]' as column: email0_
09:20:50,311 DEBUG StringType:123 - returning '' as column: pager0_
09:20:50,342 DEBUG DateType:123 - returning '02 May 2006' as column: STAMP0_
09:20:50,342 DEBUG IntegerType:123 - returning '33' as column: UNIQUEID0_
09:20:50,342 DEBUG IntegerType:123 - returning '0' as column: customer2_0_
09:20:50,342 DEBUG StringType:123 - returning 'companya' as column: context0_
09:20:50,342 DEBUG StringType:123 - returning '420' as column: mailbox0_
09:20:50,342 DEBUG StringType:123 - returning '1234' as column: password0_
09:20:50,342 DEBUG StringType:123 - returning 'John Bigelow' as column: fullname0_
09:20:50,342 DEBUG StringType:123 - returning '[email protected]' as column: email0_
09:20:50,342 DEBUG StringType:123 - returning '[email protected]' as column: pager0_
09:20:50,342 DEBUG DateType:116 - returning null as column: STAMP0_
09:20:50,342 DEBUG IntegerType:123 - returning '34' as column: UNIQUEID0_
09:20:50,342 DEBUG IntegerType:123 - returning '0' as column: customer2_0_
09:20:50,358 DEBUG StringType:123 - returning 'companyb' as column: context0_
09:20:50,358 DEBUG StringType:123 - returning '1234' as column: mailbox0_
09:20:50,358 DEBUG StringType:123 - returning '1234' as column: password0_
09:20:50,358 DEBUG StringType:123 - returning 'bad record' as column: fullname0_
09:20:50,358 DEBUG StringType:123 - returning 'no valid email' as column: email0_
09:20:50,358 DEBUG StringType:123 - returning '' as column: pager0_
09:20:50,358 DEBUG DateType:123 - returning '18 May 2006' as column: STAMP0_
........more records of the same.............
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
09:20:50,639 DEBUG IntegerType:79 - binding '0' to parameter: 1
09:20:50,639 DEBUG StringType:79 - binding 'companya' to parameter: 2
09:20:50,639 DEBUG StringType:79 - binding '555359664101' to parameter: 3
09:20:50,639 DEBUG StringType:79 - binding '1234' to parameter: 4
09:20:50,639 DEBUG StringType:79 - binding 'Asterisk Test' to parameter: 5
09:20:50,639 DEBUG StringType:79 - binding '[email protected]' to parameter: 6
09:20:50,639 DEBUG StringType:71 - binding null to parameter: 7
09:20:50,639 DEBUG DateType:79 - binding '02 May 2006' to parameter: 8
09:20:50,639 DEBUG IntegerType:79 - binding '32' to parameter: 9
Hibernate: update VOICEMAIL_USERS set customer_id=?, context=?, mailbox=?, password=?, fullname=?, email=?, pager=?, STAMP=? where UNIQUEID=?
09:20:50,639 DEBUG IntegerType:79 - binding '0' to parameter: 1
09:20:50,639 DEBUG StringType:79 - binding 'companyb' to parameter: 2
09:20:50,639 DEBUG StringType:79 - binding '1234' to parameter: 3
09:20:50,639 DEBUG StringType:79 - binding '1234' to parameter: 4
09:20:50,639 DEBUG StringType:79 - binding 'bad record' to parameter: 5
09:20:50,655 DEBUG StringType:79 - binding 'no valid email' to parameter: 6
09:20:50,655 DEBUG StringType:71 - binding null to parameter: 7
09:20:50,655 DEBUG DateType:79 - binding '18 May 2006' to parameter: 8
09:20:50,655 DEBUG IntegerType:79 - binding '34' to parameter: 9
........more records of the same.............
09:20:50,780 WARN JDBCExceptionReporter:71 - SQL Error: 1263, SQLState: 22004
09:20:50,780 ERROR JDBCExceptionReporter:72 - Column set to default value; NULL supplied to NOT NULL column 'pager' at row 1
09:20:50,780 ERROR AbstractFlushingEventListener:299 - Could not synchronize database state with session
org.hibernate.exception.DataException: could not update: [com.emergent_netsolutions.pbx.VoicemailUsers#47]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:75)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2222)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2118)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2374)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:84)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1009)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:361)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at com.emergent_netsolutions.pbx.VoicemailUsersManager.getAllVoiceMailUsers(VoicemailUsersManager.java:103)
at com.emergent_netsolutions.pbx.VoicemailUsersManager.main(VoicemailUsersManager.java:42)
Caused by: java.sql.BatchUpdateException: Column set to default value; NULL supplied to NOT NULL column 'pager' at row 1
at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:642)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
at org.hibernate.jdbc.BatchingBatcher.addToBatch(BatchingBatcher.java:34)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2204)
... 13 more
org.hibernate.exception.DataException: could not update: [com.emergent_netsolutions.pbx.VoicemailUsers#47]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:75)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2222)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2118)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2374)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:84)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1009)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:361)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at com.emergent_netsolutions.pbx.VoicemailUsersManager.getAllVoiceMailUsers(VoicemailUsersManager.java:103)
at com.emergent_netsolutions.pbx.VoicemailUsersManager.main(VoicemailUsersManager.java:42)
Caused by: java.sql.BatchUpdateException: Column set to default value; NULL supplied to NOT NULL column 'pager' at row 1
at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:642)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
at org.hibernate.jdbc.BatchingBatcher.addToBatch(BatchingBatcher.java:34)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2204)
... 13 more
Exception in thread "main"

dynoweb · **Joined:** Wed May 17, 2006 6:06 pm **Posts:** 8

Oh ya, here's a segment of the stacktrace with the check for null in the POJO. The execption only occured once even though there are many records with an empty string PAGER value.

Code:

09:48:42,530 INFO SettingsFactory:213 - Query cache: disabled
09:48:42,530 INFO SettingsFactory:325 - Cache provider: org.hibernate.cache.NoCacheProvider
09:48:42,546 INFO SettingsFactory:228 - Optimize cache for minimal puts: disabled
09:48:42,546 INFO SettingsFactory:237 - Structured second-level cache entries: disabled
09:48:42,546 INFO SettingsFactory:257 - Echoing all SQL to stdout
09:48:42,546 INFO SettingsFactory:264 - Statistics: disabled
09:48:42,546 INFO SettingsFactory:268 - Deleted entity synthetic identifier rollback: disabled
09:48:42,546 INFO SettingsFactory:283 - Default entity-mode: pojo
09:48:42,592 INFO SessionFactoryImpl:153 - building session factory
Null pager!
java.lang.Exception
at com.emergent_netsolutions.pbx.VoicemailUsers.setPager(VoicemailUsers.java:77)
at com.emergent_netsolutions.pbx.VoicemailUsers$$BulkBeanByCGLIB$$128014d1.setPropertyValues(<generated>)
at org.hibernate.util.ReflectHelper.getBulkBean(ReflectHelper.java:198)
at org.hibernate.tuple.PojoEntityTuplizer.<init>(PojoEntityTuplizer.java:84)
at org.hibernate.tuple.TuplizerLookup.create(TuplizerLookup.java:64)
at org.hibernate.tuple.EntityMetamodel.<init>(EntityMetamodel.java:257)
at org.hibernate.persister.entity.AbstractEntityPersister.<init>(AbstractEntityPersister.java:412)
at org.hibernate.persister.entity.SingleTableEntityPersister.<init>(SingleTableEntityPersister.java:108)
at org.hibernate.persister.PersisterFactory.createClassPersister(PersisterFactory.java:55)
at org.hibernate.impl.SessionFactoryImpl.<init>(SessionFactoryImpl.java:215)
at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1176)
at util.HibernateUtil.<clinit>(HibernateUtil.java:13)
at com.emergent_netsolutions.pbx.VoicemailUsersManager.main(VoicemailUsersManager.java:41)
09:48:43,014 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
09:48:43,014 INFO SessionFactoryImpl:728 - closing
09:48:43,014 INFO DriverManagerConnectionProvider:147 - cleaning up connection pool: jdbc:mysql://localhost/emergentpbx?zeroDateTimeBehavior=convertToNull&emptyStringsConvertToZero=false
Hibernate: select voicemailu0_.UNIQUEID as UNIQUEID0_, voicemailu0_.customer_id as customer2_0_, voicemailu0_.context as context0_, voicemailu0_.mailbox as mailbox0_, voicemailu0_.password as password0_, voicemailu0_.fullname as fullname0_, voicemailu0_.email as email0_, voicemailu0_.pager as pager0_, voicemailu0_.STAMP as STAMP0_ from VOICEMAIL_USERS voicemailu0_
09:48:43,452 DEBUG IntegerType:123 - returning '32' as column: UNIQUEID0_
09:48:43,467 DEBUG IntegerType:123 - returning '0' as column: customer2_0_
09:48:43,467 DEBUG StringType:123 - returning 'companya' as column: context0_
09:48:43,467 DEBUG StringType:123 - returning '555359664101' as column: mailbox0_
09:48:43,467 DEBUG StringType:123 - returning '1234' as column: password0_
09:48:43,467 DEBUG StringType:123 - returning 'Asterisk Test' as column: fullname0_
09:48:43,467 DEBUG StringType:123 - returning '[email protected]' as column: email0_
09:48:43,467 DEBUG StringType:123 - returning '' as column: pager0_
09:48:43,499 DEBUG DateType:123 - returning '02 May 2006' as column: STAMP0_
09:48:43,499 DEBUG IntegerType:123 - returning '33' as column: UNIQUEID0_
09:48:43,499 DEBUG IntegerType:123 - returning '0' as column: customer2_0_
09:48:43,499 DEBUG StringType:123 - returning 'companya' as column: context0_
09:48:43,514 DEBUG StringType:123 - returning '420' as column: mailbox0_
09:48:43,514 DEBUG StringType:123 - returning '1234' as column: password0_
09:48:43,514 DEBUG StringType:123 - returning 'John Bigelow' as column: fullname0_
09:48:43,514 DEBUG StringType:123 - returning '[email protected]' as column: email0_
09:48:43,514 DEBUG StringType:123 - returning '[email protected]' as column: pager0_
09:48:43,514 DEBUG DateType:116 - returning null as column: STAMP0_

tenwit · **Joined:** Thu Dec 23, 2004 9:08 pm **Posts:** 2008

Weird that the only time setPager(null) was called was during the session factory creation, almost a full second before your first select. I'm not certain that the empty pager value that we see in the parameter tracing is in any way related to the stack trace. Do you know why a VoicemailUsers object is being created at that point? And more importantly, why is an object that hibernate created without going to the database being later saved to the database?

I guess I'm missing something, but I can't figure out why we're seeing output like that.

dynoweb · **Joined:** Wed May 17, 2006 6:06 pm **Posts:** 8

I suspect the empty pager value that we see is happening when Hibernate is using reflection to see what the POJO looks like and not actually when it's creating record objects.

I think what we might be seeing is a bug in how hibernate deals with XML. If the string is empty, it can't tell if it's null or empty.

mschulz · **Joined:** Sat Jan 31, 2004 7:19 pm **Posts:** 39

Just removing the not-null from your Pager property should address the
issue. That is clearer anyway, as the NOT NULL is guaranteed only at
the DB side, the JDBC driver and hence the user definitely _can_ pass
in a null value here.

Hibernate seems to go through the movements to check which objects
are clean and appears to be stumbling across those with null values.

And your assessment is correct that Hibernate would have
difficulties distinguishing between "" and NULL.

More precisely, in most databases you are going to find that "" is treated as NULL.

wfcheang · **Joined:** Tue May 03, 2005 1:53 am **Posts:** 7

I am having the same problem. It seems the problem is related to second level cache. If I turn the cache off, it solves the problem. I am using custom UserType for my typesafe enum field. With cache turned on, UserType's nullSafeGet sometimes does not get called.

Can anyone confirm if this is a bug?