<?xml version="1.0" encoding="ISO-8859-1"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping>
  <class table="person" name="org.gbif.model.Person">
   <cache usage="read-write"/>
    <id column="id" unsaved-value="null" access="property" name="id">
      <generator class="increment"/>
    </id>
    <property name="name" not-null="true" access="property" column="name"/>
  </class>
</hibernate-mapping>

         String name = "Tim";
         
         // only one SQL statement comes out the logs...
         // cache is working
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();

         // create a person
         // the UpdateTimestampsCache will now say that
         // the above query is old
         Person person = new Person();
         person.setName("Tom");
         session.save(person);
         
         // First one - TimestampCache says it invalid - ok
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();
         // why is this not read from cache? - The DB is hit
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();

Hibernate: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
-- note that this only appears once (second call cache is being used)

Hibernate: select max(id) from person
Hibernate: insert into person (name, id) values (?, ?)

-- Ok - first one I can understand - cache is old since the insert
-- but why twice?
Hibernate: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
Hibernate: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?

INFO  [Environment]  Hibernate 3.1.3
INFO  [Environment]  hibernate.properties not found
INFO  [Environment]  using CGLIB reflection optimizer
INFO  [Environment]  using JDK 1.4 java.sql.Timestamp handling
INFO  [Configuration]  configuring from resource: /hibernate.cfg.xml
INFO  [Configuration]  Configuration resource: /hibernate.cfg.xml
DEBUG [DTDEntityResolver]  trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
DEBUG [DTDEntityResolver]  recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
DEBUG [DTDEntityResolver]  located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
DEBUG [Configuration]  hibernate.dialect=org.hibernate.dialect.MySQLDialect
DEBUG [Configuration]  hibernate.cache.use_query_cache=true
DEBUG [Configuration]  hibernate.show_sql=true
DEBUG [Configuration]  hibernate.connection.driver_class=com.mysql.jdbc.Driver
DEBUG [Configuration]  hibernate.connection.url=jdbc:mysql://localhost:3306/gbifPortal
DEBUG [Configuration]  hibernate.connection.username=root
DEBUG [Configuration]  hibernate.connection.password=password
DEBUG [Configuration]  null<-org.dom4j.tree.DefaultAttribute@1549f94 [Attribute: name resource value "org/gbif/model/Person.hbm.xml"]
INFO  [Configuration]  Reading mappings from resource: org/gbif/model/Person.hbm.xml
DEBUG [DTDEntityResolver]  trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
DEBUG [DTDEntityResolver]  recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
DEBUG [DTDEntityResolver]  located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
INFO  [HbmBinder]  Mapping class: org.gbif.model.Person -> person
DEBUG [HbmBinder]  Mapped property: id -> id
DEBUG [HbmBinder]  Mapped property: name -> name
INFO  [Configuration]  Configured SessionFactory: null
DEBUG [Configuration]  properties: {hibernate.connection.password=password, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=C:\Program Files\Java\jre1.5.0_05\bin, java.vm.version=1.5.0_05-b05, hibernate.connection.username=root, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, hibernate.cache.use_query_cache=true, path.separator=;, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=Service Pack 2, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\gbif\h8test, java.runtime.version=1.5.0_05-b05, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\Program Files\Java\jre1.5.0_05\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\TROBER~1\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.jnu.encoding=Cp1252, java.library.path=C:\Program Files\Java\jre1.5.0_05\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Java\jdk1.5.0_05\bin;C:\apache-ant-1.6.5\bin;;C:\Program Files\cvsnt;c:\php;C:\maven-2.0.2\bin;C:\Program Files\Common Files\GTK\2.0\bin;F:\mysql\mysql5\bin;, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, os.version=5.1, user.home=C:\Documents and Settings\trobertson, user.timezone=, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.5, hibernate.connection.driver_class=com.mysql.jdbc.Driver, user.name=trobertson, java.class.path=C:\gbif\h8test\bin;C:\gbif\dependencies\lib\ant\ant-contrib-1.0b1.jar;C:\gbif\dependencies\lib\axis\wsdl4j-1.5.1.jar;C:\gbif\dependencies\lib\axis\axis-ant.jar;C:\gbif\dependencies\lib\axis\jaxrpc.jar;C:\gbif\dependencies\lib\axis\saaj.jar;C:\gbif\dependencies\lib\dom4j\jaxen-1.1-beta-4.jar;C:\gbif\dependencies\lib\dom4j\dom4j-1.6.1.jar;C:\gbif\dependencies\lib\ehcache\ehcache-1.1.jar;C:\gbif\dependencies\lib\hibernate\jta.jar;C:\gbif\dependencies\lib\hibernate\antlr-2.7.5H3.jar;C:\gbif\dependencies\lib\hibernate\hibernate3.jar;C:\gbif\dependencies\lib\hibernate\hibernate-tools.jar;C:\gbif\dependencies\lib\j2ee\xml-apis.jar;C:\gbif\dependencies\lib\j2ee\activation.jar;C:\gbif\dependencies\lib\j2ee\connector.jar;C:\gbif\dependencies\lib\j2ee\ejb.jar;C:\gbif\dependencies\lib\j2ee\jaxrpc.jar;C:\gbif\dependencies\lib\j2ee\jdbc2_0-stdext.jar;C:\gbif\dependencies\lib\j2ee\jms.jar;C:\gbif\dependencies\lib\j2ee\jsp-api.jar;C:\gbif\dependencies\lib\j2ee\jstl.jar;C:\gbif\dependencies\lib\j2ee\jta.jar;C:\gbif\dependencies\lib\j2ee\mail.jar;C:\gbif\dependencies\lib\j2ee\rowset.jar;C:\gbif\dependencies\lib\j2ee\servlet-api.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-validator.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-attributes-api.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-attributes-compiler.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-beanutils.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-codec.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-collections-3.1.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-dbcp-1.2.1.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-digester-1.7.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-discovery.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-fileupload.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-httpclient.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-lang-2.1.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-logging.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-pool-1.2.jar;C:\gbif\dependencies\lib\jdom\jdom-1.0.jar;C:\gbif\dependencies\lib\junit\ant-junit.jar;C:\gbif\dependencies\lib\log4j\log4j-1.2.12.jar;C:\gbif\dependencies\lib\spring\spring-webmvc.jar;C:\gbif\dependencies\lib\spring\asm.jar;C:\gbif\dependencies\lib\spring\cglib-2.1.2.jar;C:\gbif\dependencies\lib\spring\spring.jar;C:\gbif\dependencies\lib\spring\spring-aop.jar;C:\gbif\dependencies\lib\spring\spring-beans.jar;C:\gbif\dependencies\lib\spring\spring-context.jar;C:\gbif\dependencies\lib\spring\spring-core.jar;C:\gbif\dependencies\lib\spring\spring-dao.jar;C:\gbif\dependencies\lib\spring\spring-hibernate.jar;C:\gbif\dependencies\lib\spring\spring-jdbc.jar;C:\gbif\dependencies\lib\spring\spring-mock.jar;C:\gbif\dependencies\lib\spring\spring-orm.jar;C:\gbif\dependencies\lib\spring\spring-remoting.jar;C:\gbif\dependencies\lib\spring\spring-support.jar;C:\gbif\dependencies\lib\spring\spring-web.jar;C:\gbif\dependencies\lib\struts\struts.jar;C:\gbif\dependencies\lib\velocity\velocity-tools-view-1.1.jar;C:\gbif\dependencies\lib\velocity\jtidy-r8-21122004.jar;C:\gbif\dependencies\lib\velocity\velocity-1.4.jar;C:\gbif\dependencies\lib\velocity\velocity-tools-generic-1.1.jar;C:\gbif\dependencies\lib\xdoclet\xjavadoc-1.1.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-apache-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-ejb-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-hibernate-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-java-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-spring-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-web-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-xdoclet-module-1.2.3.jar;C:\gbif\dependencies\lib\xfire\stax-api-1.0.jar;C:\gbif\dependencies\lib\xfire\wsdl4j-qname-1.4.jar;C:\gbif\dependencies\lib\xfire\wstx-asl-2.8.jar;C:\gbif\dependencies\lib\xfire\wstx-lgpl-2.8.jar;C:\gbif\dependencies\lib\xfire\xbean-spring-2.0.jar;C:\gbif\dependencies\lib\junit\junit.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\xmlpublic.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\jsr173_1.0_api.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\resolver.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\xbean.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\xbean_xpath.jar;C:\gbif\dependencies\lib\xfire\XmlSchema-20051110.jar;C:\gbif\dependencies\lib\jakarta-taglibs\standard.jar;C:\gbif\dependencies\lib\jakarta-taglibs\jstl.jar;C:\gbif\dependencies\lib\castor-1.0\castor-1.0M2.jar;C:\gbif\dependencies\lib\xfire\xfire-all-1.1-beta-1.jar;C:\gbif\dependencies\lib\uddi4j\uddi4j.jar;C:\gbif\dependencies\lib\apache-soap\soap.jar;C:\gbif\dependencies\lib\xerces-2.6.2\xml-apis.jar;C:\gbif\dependencies\lib\xerces-2.6.2\xercesImpl.jar;C:\gbif\dependencies\lib\mysql-connector\mysql-connector-java-3.1.12-bin.jar;C:\gbif\dependencies\lib\axis\axis.jar;C:\gbif\portalmodel\bin, hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=C:\Program Files\Java\jre1.5.0_05, sun.arch.data.model=32, hibernate.connection.url=jdbc:mysql://localhost:3306/gbifPortal, hibernate.dialect=org.hibernate.dialect.MySQLDialect, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.5.0_05, java.ext.dirs=C:\Program Files\Java\jre1.5.0_05\lib\ext, sun.boot.class.path=C:\Program Files\Java\jre1.5.0_05\lib\rt.jar;C:\Program Files\Java\jre1.5.0_05\lib\i18n.jar;C:\Program Files\Java\jre1.5.0_05\lib\sunrsasign.jar;C:\Program Files\Java\jre1.5.0_05\lib\jsse.jar;C:\Program Files\Java\jre1.5.0_05\lib\jce.jar;C:\Program Files\Java\jre1.5.0_05\lib\charsets.jar;C:\Program Files\Java\jre1.5.0_05\classes, java.vendor=Sun Microsystems Inc., file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, sun.desktop=windows, sun.cpu.isalist=}
DEBUG [Configuration]  Preparing to build session factory with filters : {}
DEBUG [Configuration]  processing extends queue
DEBUG [Configuration]  processing collection mappings
DEBUG [Configuration]  processing native query and ResultSetMapping mappings
DEBUG [Configuration]  processing association property references
DEBUG [Configuration]  processing foreign key constraints
INFO  [DriverManagerConnectionProvider]  Using Hibernate built-in connection pool (not for production use!)
INFO  [DriverManagerConnectionProvider]  Hibernate connection pool size: 20
INFO  [DriverManagerConnectionProvider]  autocommit mode: false
INFO  [DriverManagerConnectionProvider]  using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/gbifPortal
INFO  [DriverManagerConnectionProvider]  connection properties: {user=root, password=password}
DEBUG [DriverManagerConnectionProvider]  total checked-out connections: 0
DEBUG [DriverManagerConnectionProvider]  opening new JDBC connection
DEBUG [DriverManagerConnectionProvider]  created connection to: jdbc:mysql://localhost:3306/gbifPortal, Isolation Level: 4
INFO  [SettingsFactory]  RDBMS: MySQL, version: 5.0.15-nt
INFO  [SettingsFactory]  JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.12 ( $Date: 2005-11-17 15:53:48 +0100 (Thu, 17 Nov 2005) $, $Revision$ )
DEBUG [DriverManagerConnectionProvider]  returning connection to pool, pool size: 1
INFO  [Dialect]  Using dialect: org.hibernate.dialect.MySQLDialect
INFO  [TransactionFactoryFactory]  Using default transaction strategy (direct JDBC transactions)
INFO  [TransactionManagerLookupFactory]  No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
INFO  [SettingsFactory]  Automatic flush during beforeCompletion(): disabled
INFO  [SettingsFactory]  Automatic session close at end of transaction: disabled
INFO  [SettingsFactory]  JDBC batch size: 15
INFO  [SettingsFactory]  JDBC batch updates for versioned data: disabled
INFO  [SettingsFactory]  Scrollable result sets: enabled
DEBUG [SettingsFactory]  Wrap result sets: disabled
INFO  [SettingsFactory]  JDBC3 getGeneratedKeys(): enabled
INFO  [SettingsFactory]  Connection release mode: auto
INFO  [SettingsFactory]  Maximum outer join fetch depth: 2
INFO  [SettingsFactory]  Default batch fetch size: 1
INFO  [SettingsFactory]  Generate SQL with comments: disabled
INFO  [SettingsFactory]  Order SQL updates by primary key: disabled
INFO  [SettingsFactory]  Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
INFO  [ASTQueryTranslatorFactory]  Using ASTQueryTranslatorFactory
INFO  [SettingsFactory]  Query language substitutions: {}
INFO  [SettingsFactory]  Second-level cache: enabled
INFO  [SettingsFactory]  Query cache: enabled
INFO  [SettingsFactory]  Cache provider: org.hibernate.cache.EhCacheProvider
INFO  [SettingsFactory]  Optimize cache for minimal puts: disabled
INFO  [SettingsFactory]  Structured second-level cache entries: disabled
INFO  [SettingsFactory]  Query cache factory: org.hibernate.cache.StandardQueryCacheFactory
DEBUG [SQLExceptionConverterFactory]  Using dialect defined converter
INFO  [SettingsFactory]  Echoing all SQL to stdout
INFO  [SettingsFactory]  Statistics: disabled
INFO  [SettingsFactory]  Deleted entity synthetic identifier rollback: disabled
INFO  [SettingsFactory]  Default entity-mode: pojo
INFO  [SessionFactoryImpl]  building session factory
DEBUG [SessionFactoryImpl]  Session factory constructed with filter configurations : {}
DEBUG [SessionFactoryImpl]  instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, hibernate.connection.password=password, sun.boot.library.path=C:\Program Files\Java\jre1.5.0_05\bin, java.vm.version=1.5.0_05-b05, hibernate.connection.username=root, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=;, hibernate.cache.use_query_cache=true, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=Service Pack 2, java.vm.specification.name=Java Virtual Machine Specification, user.dir=C:\gbif\h8test, java.runtime.version=1.5.0_05-b05, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\Program Files\Java\jre1.5.0_05\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\TROBER~1\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows XP, sun.jnu.encoding=Cp1252, java.library.path=C:\Program Files\Java\jre1.5.0_05\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Java\jdk1.5.0_05\bin;C:\apache-ant-1.6.5\bin;;C:\Program Files\cvsnt;c:\php;C:\maven-2.0.2\bin;C:\Program Files\Common Files\GTK\2.0\bin;F:\mysql\mysql5\bin;, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, os.version=5.1, user.home=C:\Documents and Settings\trobertson, user.timezone=, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.5, hibernate.connection.driver_class=com.mysql.jdbc.Driver, java.class.path=C:\gbif\h8test\bin;C:\gbif\dependencies\lib\ant\ant-contrib-1.0b1.jar;C:\gbif\dependencies\lib\axis\wsdl4j-1.5.1.jar;C:\gbif\dependencies\lib\axis\axis-ant.jar;C:\gbif\dependencies\lib\axis\jaxrpc.jar;C:\gbif\dependencies\lib\axis\saaj.jar;C:\gbif\dependencies\lib\dom4j\jaxen-1.1-beta-4.jar;C:\gbif\dependencies\lib\dom4j\dom4j-1.6.1.jar;C:\gbif\dependencies\lib\ehcache\ehcache-1.1.jar;C:\gbif\dependencies\lib\hibernate\jta.jar;C:\gbif\dependencies\lib\hibernate\antlr-2.7.5H3.jar;C:\gbif\dependencies\lib\hibernate\hibernate3.jar;C:\gbif\dependencies\lib\hibernate\hibernate-tools.jar;C:\gbif\dependencies\lib\j2ee\xml-apis.jar;C:\gbif\dependencies\lib\j2ee\activation.jar;C:\gbif\dependencies\lib\j2ee\connector.jar;C:\gbif\dependencies\lib\j2ee\ejb.jar;C:\gbif\dependencies\lib\j2ee\jaxrpc.jar;C:\gbif\dependencies\lib\j2ee\jdbc2_0-stdext.jar;C:\gbif\dependencies\lib\j2ee\jms.jar;C:\gbif\dependencies\lib\j2ee\jsp-api.jar;C:\gbif\dependencies\lib\j2ee\jstl.jar;C:\gbif\dependencies\lib\j2ee\jta.jar;C:\gbif\dependencies\lib\j2ee\mail.jar;C:\gbif\dependencies\lib\j2ee\rowset.jar;C:\gbif\dependencies\lib\j2ee\servlet-api.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-validator.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-attributes-api.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-attributes-compiler.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-beanutils.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-codec.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-collections-3.1.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-dbcp-1.2.1.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-digester-1.7.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-discovery.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-fileupload.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-httpclient.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-lang-2.1.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-logging.jar;C:\gbif\dependencies\lib\jakarta-commons\commons-pool-1.2.jar;C:\gbif\dependencies\lib\jdom\jdom-1.0.jar;C:\gbif\dependencies\lib\junit\ant-junit.jar;C:\gbif\dependencies\lib\log4j\log4j-1.2.12.jar;C:\gbif\dependencies\lib\spring\spring-webmvc.jar;C:\gbif\dependencies\lib\spring\asm.jar;C:\gbif\dependencies\lib\spring\cglib-2.1.2.jar;C:\gbif\dependencies\lib\spring\spring.jar;C:\gbif\dependencies\lib\spring\spring-aop.jar;C:\gbif\dependencies\lib\spring\spring-beans.jar;C:\gbif\dependencies\lib\spring\spring-context.jar;C:\gbif\dependencies\lib\spring\spring-core.jar;C:\gbif\dependencies\lib\spring\spring-dao.jar;C:\gbif\dependencies\lib\spring\spring-hibernate.jar;C:\gbif\dependencies\lib\spring\spring-jdbc.jar;C:\gbif\dependencies\lib\spring\spring-mock.jar;C:\gbif\dependencies\lib\spring\spring-orm.jar;C:\gbif\dependencies\lib\spring\spring-remoting.jar;C:\gbif\dependencies\lib\spring\spring-support.jar;C:\gbif\dependencies\lib\spring\spring-web.jar;C:\gbif\dependencies\lib\struts\struts.jar;C:\gbif\dependencies\lib\velocity\velocity-tools-view-1.1.jar;C:\gbif\dependencies\lib\velocity\jtidy-r8-21122004.jar;C:\gbif\dependencies\lib\velocity\velocity-1.4.jar;C:\gbif\dependencies\lib\velocity\velocity-tools-generic-1.1.jar;C:\gbif\dependencies\lib\xdoclet\xjavadoc-1.1.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-apache-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-ejb-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-hibernate-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-java-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-spring-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-web-module-1.2.3.jar;C:\gbif\dependencies\lib\xdoclet\xdoclet-xdoclet-module-1.2.3.jar;C:\gbif\dependencies\lib\xfire\stax-api-1.0.jar;C:\gbif\dependencies\lib\xfire\wsdl4j-qname-1.4.jar;C:\gbif\dependencies\lib\xfire\wstx-asl-2.8.jar;C:\gbif\dependencies\lib\xfire\wstx-lgpl-2.8.jar;C:\gbif\dependencies\lib\xfire\xbean-spring-2.0.jar;C:\gbif\dependencies\lib\junit\junit.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\xmlpublic.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\jsr173_1.0_api.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\resolver.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\xbean.jar;C:\gbif\dependencies\lib\xmlbeans-2-1-0\xbean_xpath.jar;C:\gbif\dependencies\lib\xfire\XmlSchema-20051110.jar;C:\gbif\dependencies\lib\jakarta-taglibs\standard.jar;C:\gbif\dependencies\lib\jakarta-taglibs\jstl.jar;C:\gbif\dependencies\lib\castor-1.0\castor-1.0M2.jar;C:\gbif\dependencies\lib\xfire\xfire-all-1.1-beta-1.jar;C:\gbif\dependencies\lib\uddi4j\uddi4j.jar;C:\gbif\dependencies\lib\apache-soap\soap.jar;C:\gbif\dependencies\lib\xerces-2.6.2\xml-apis.jar;C:\gbif\dependencies\lib\xerces-2.6.2\xercesImpl.jar;C:\gbif\dependencies\lib\mysql-connector\mysql-connector-java-3.1.12-bin.jar;C:\gbif\dependencies\lib\axis\axis.jar;C:\gbif\portalmodel\bin, user.name=trobertson, hibernate.show_sql=true, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=C:\Program Files\Java\jre1.5.0_05, hibernate.dialect=org.hibernate.dialect.MySQLDialect, hibernate.connection.url=jdbc:mysql://localhost:3306/gbifPortal, java.specification.vendor=Sun Microsystems Inc., user.language=en, awt.toolkit=sun.awt.windows.WToolkit, java.vm.info=mixed mode, hibernate.cglib.use_reflection_optimizer=true, java.version=1.5.0_05, java.ext.dirs=C:\Program Files\Java\jre1.5.0_05\lib\ext, sun.boot.class.path=C:\Program Files\Java\jre1.5.0_05\lib\rt.jar;C:\Program Files\Java\jre1.5.0_05\lib\i18n.jar;C:\Program Files\Java\jre1.5.0_05\lib\sunrsasign.jar;C:\Program Files\Java\jre1.5.0_05\lib\jsse.jar;C:\Program Files\Java\jre1.5.0_05\lib\jce.jar;C:\Program Files\Java\jre1.5.0_05\lib\charsets.jar;C:\Program Files\Java\jre1.5.0_05\classes, java.vendor=Sun Microsystems Inc., file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.desktop=windows, sun.cpu.isalist=}
DEBUG [CacheManager]  Creating new CacheManager with default config
DEBUG [CacheManager]  Configuring ehcache from classpath.
DEBUG [Configurator]  Configuring ehcache from ehcache.xml found in the classpath: file:/C:/gbif/h8test/bin/ehcache.xml
DEBUG [Configuration$DiskStore]  Disk Store Path: C:\DOCUME~1\TROBER~1\LOCALS~1\Temp\
DEBUG [CacheFactory]  instantiating cache region: org.gbif.model.Person usage strategy: read-write
WARN  [EhCacheProvider]  Could not find configuration [org.gbif.model.Person]; using defaults.
DEBUG [MemoryStore]  org.gbif.model.Person Cache: Using SpoolingLinkedHashMap implementation
DEBUG [MemoryStore]  initialized MemoryStore for org.gbif.model.Person
DEBUG [Cache]  Initialised cache: org.gbif.model.Person
DEBUG [EhCacheProvider]  started EHCache region: org.gbif.model.Person
DEBUG [AbstractEntityPersister]  Static SQL for entity: org.gbif.model.Person
DEBUG [AbstractEntityPersister]   Version select: select id from person where id =?
DEBUG [AbstractEntityPersister]   Snapshot select: select person_.id, person_.name as name0_ from person person_ where person_.id=?
DEBUG [AbstractEntityPersister]   Insert 0: insert into person (name, id) values (?, ?)
DEBUG [AbstractEntityPersister]   Update 0: update person set name=? where id=?
DEBUG [AbstractEntityPersister]   Delete 0: delete from person where id=?
DEBUG [EntityLoader]  Static select for entity org.gbif.model.Person: select person0_.id as id0_0_, person0_.name as name0_0_ from person person0_ where person0_.id=?
DEBUG [EntityLoader]  Static select for entity org.gbif.model.Person: select person0_.id as id0_0_, person0_.name as name0_0_ from person person0_ where person0_.id=?
DEBUG [EntityLoader]  Static select for entity org.gbif.model.Person: select person0_.id as id0_0_, person0_.name as name0_0_ from person person0_ where person0_.id=? for update
DEBUG [EntityLoader]  Static select for entity org.gbif.model.Person: select person0_.id as id0_0_, person0_.name as name0_0_ from person person0_ where person0_.id=? for update
DEBUG [EntityLoader]  Static select for action ACTION_MERGE on entity org.gbif.model.Person: select person0_.id as id0_0_, person0_.name as name0_0_ from person person0_ where person0_.id=?
DEBUG [EntityLoader]  Static select for action ACTION_REFRESH on entity org.gbif.model.Person: select person0_.id as id0_0_, person0_.name as name0_0_ from person person0_ where person0_.id=?
DEBUG [SessionFactoryObjectFactory]  initializing class SessionFactoryObjectFactory
DEBUG [SessionFactoryObjectFactory]  registered: 40a69c960af96e2f010af96e31650000 (unnamed)
INFO  [SessionFactoryObjectFactory]  Not binding factory to JNDI, no JNDI name configured
DEBUG [SessionFactoryImpl]  instantiated session factory
INFO  [UpdateTimestampsCache]  starting update timestamps cache at region: org.hibernate.cache.UpdateTimestampsCache
WARN  [EhCacheProvider]  Could not find configuration [org.hibernate.cache.UpdateTimestampsCache]; using defaults.
DEBUG [MemoryStore]  org.hibernate.cache.UpdateTimestampsCache Cache: Using SpoolingLinkedHashMap implementation
DEBUG [MemoryStore]  initialized MemoryStore for org.hibernate.cache.UpdateTimestampsCache
DEBUG [Cache]  Initialised cache: org.hibernate.cache.UpdateTimestampsCache
DEBUG [EhCacheProvider]  started EHCache region: org.hibernate.cache.UpdateTimestampsCache
INFO  [StandardQueryCache]  starting query cache at region: org.hibernate.cache.StandardQueryCache
WARN  [EhCacheProvider]  Could not find configuration [org.hibernate.cache.StandardQueryCache]; using defaults.
DEBUG [MemoryStore]  org.hibernate.cache.StandardQueryCache Cache: Using SpoolingLinkedHashMap implementation
DEBUG [MemoryStore]  initialized MemoryStore for org.hibernate.cache.StandardQueryCache
DEBUG [Cache]  Initialised cache: org.hibernate.cache.StandardQueryCache
DEBUG [EhCacheProvider]  started EHCache region: org.hibernate.cache.StandardQueryCache
DEBUG [SessionFactoryImpl]  Checking 0 named HQL queries
DEBUG [SessionFactoryImpl]  Checking 0 named SQL queries
DEBUG [SessionImpl]  opened session at timestamp: 4696662217216000
DEBUG [QueryPlanCache]  unable to locate HQL query plan in cache; generating (from Person p where p.name=? )
DEBUG [QueryTranslatorImpl]  parse() - HQL: from org.gbif.model.Person p where p.name=?
DEBUG [AST]  --- HQL AST ---
\-[QUERY] 'query'
    +-[SELECT_FROM] 'SELECT_FROM'
    |  \-[FROM] 'from'
    |     \-[RANGE] 'RANGE'
    |        +-[DOT] '.'
    |        |  +-[DOT] '.'
    |        |  |  +-[DOT] '.'
    |        |  |  |  +-[IDENT] 'org'
    |        |  |  |  \-[IDENT] 'gbif'
    |        |  |  \-[IDENT] 'model'
    |        |  \-[IDENT] 'Person'
    |        \-[ALIAS] 'p'
    \-[WHERE] 'where'
       \-[EQ] '='
          +-[DOT] '.'
          |  +-[IDENT] 'p'
          |  \-[IDENT] 'name'
          \-[PARAM] '?'

DEBUG [ErrorCounter]  throwQueryException() : no errors
DEBUG [HqlSqlBaseWalker]  select << begin [level=1, statement=select]
DEBUG [FromElement]  FromClause{level=1} :  org.gbif.model.Person (p) -> person0_
DEBUG [FromReferenceNode]  Resolved :  p -> person0_.id
DEBUG [DotNode]  getDataType() : name -> org.hibernate.type.StringType@7cd37a
DEBUG [FromReferenceNode]  Resolved :  p.name -> person0_.name
DEBUG [HqlSqlBaseWalker]  select : finishing up [level=1, statement=select]
DEBUG [HqlSqlWalker]  processQuery() :  ( SELECT ( FromClause{level=1} person person0_ ) ( where ( = ( person0_.name person0_.id name ) ? ) ) )
DEBUG [HqlSqlWalker]  Derived SELECT clause created.
DEBUG [JoinProcessor]  Using FROM fragment [person person0_]
DEBUG [HqlSqlBaseWalker]  select >> end [level=1, statement=select]
DEBUG [AST]  --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT'  querySpaces (person)
    +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
    |  +-[SELECT_EXPR] SelectExpressionImpl: 'person0_.id as id0_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=p,role=null,tableName=person,tableAlias=person0_,origin=null,colums={,className=org.gbif.model.Person}}}
    |  \-[SQL_TOKEN] SqlFragment: 'person0_.name as name0_'
    +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[p], fromElementByTableAlias=[person0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
    |  \-[FROM_FRAGMENT] FromElement: 'person person0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=p,role=null,tableName=person,tableAlias=person0_,origin=null,colums={,className=org.gbif.model.Person}}
    \-[WHERE] SqlNode: 'where'
       \-[EQ] BinaryLogicOperatorNode: '='
          +-[DOT] DotNode: 'person0_.name' {propertyName=name,dereferenceType=4,propertyPath=name,path=p.name,tableAlias=person0_,className=org.gbif.model.Person,classAlias=p}
          |  +-[ALIAS_REF] IdentNode: 'person0_.id' {alias=p, className=org.gbif.model.Person, tableAlias=person0_}
          |  \-[IDENT] IdentNode: 'name' {originalText=name}
          \-[PARAM] ParameterNode: '?' {ordinal=0, expectedType=org.hibernate.type.StringType@7cd37a}

DEBUG [ErrorCounter]  throwQueryException() : no errors
DEBUG [QueryTranslatorImpl]  HQL: from org.gbif.model.Person p where p.name=?
DEBUG [QueryTranslatorImpl]  SQL: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
DEBUG [ErrorCounter]  throwQueryException() : no errors
DEBUG [HQLQueryPlan]  HQL param location recognition took 0 mills (from Person p where p.name=? )
DEBUG [QueryPlanCache]  located HQL query plan in cache (from Person p where p.name=? )
DEBUG [HQLQueryPlan]  find: from Person p where p.name=?
DEBUG [QueryParameters]  parameters: [Tim]
DEBUG [QueryParameters]  named parameters: {}
DEBUG [StandardQueryCache]  checking cached query results in region: org.hibernate.cache.StandardQueryCache
DEBUG [EhCache]  key: sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [MemoryStore]  org.hibernate.cache.StandardQueryCacheCache: MemoryStore miss for sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [Cache]  org.hibernate.cache.StandardQueryCache cache - Miss
DEBUG [EhCache]  Element for sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {} is null
DEBUG [StandardQueryCache]  query results were not found in cache
DEBUG [AbstractBatcher]  about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG [ConnectionManager]  opening JDBC connection
DEBUG [DriverManagerConnectionProvider]  total checked-out connections: 0
DEBUG [DriverManagerConnectionProvider]  using pooled JDBC connection, pool size: 0
DEBUG [SQL]  select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
Hibernate: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
DEBUG [AbstractBatcher]  preparing statement
DEBUG [StringType]  binding 'Tim' to parameter: 1
DEBUG [AbstractBatcher]  about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG [Loader]  processing result set
DEBUG [Loader]  done processing result set (0 rows)
DEBUG [AbstractBatcher]  about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG [AbstractBatcher]  about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG [AbstractBatcher]  closing statement
DEBUG [Loader]  total objects hydrated: 0
DEBUG [StatefulPersistenceContext]  initializing non-lazy collections
DEBUG [StandardQueryCache]  caching query results in region: org.hibernate.cache.StandardQueryCache
DEBUG [Cache]  org.hibernate.cache.StandardQueryCache: Is element with key sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {} expired?: false
DEBUG [JDBCContext]  after autocommit
DEBUG [ConnectionManager]  aggressively releasing JDBC connection
DEBUG [ConnectionManager]  releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG [DriverManagerConnectionProvider]  returning connection to pool, pool size: 1
DEBUG [QueryPlanCache]  located HQL query plan in cache (from Person p where p.name=? )
DEBUG [QueryPlanCache]  located HQL query plan in cache (from Person p where p.name=? )
DEBUG [HQLQueryPlan]  find: from Person p where p.name=?
DEBUG [QueryParameters]  parameters: [Tim]
DEBUG [QueryParameters]  named parameters: {}
DEBUG [StandardQueryCache]  checking cached query results in region: org.hibernate.cache.StandardQueryCache
DEBUG [EhCache]  key: sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [MemoryStore]  org.hibernate.cache.StandardQueryCacheCache: MemoryStore hit for sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [Cache]  org.hibernate.cache.StandardQueryCache: Is element with key sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {} expired?: false
DEBUG [StandardQueryCache]  Checking query spaces for up-to-dateness: [person]
DEBUG [EhCache]  key: person
DEBUG [MemoryStore]  org.hibernate.cache.UpdateTimestampsCacheCache: MemoryStore miss for person
DEBUG [Cache]  org.hibernate.cache.UpdateTimestampsCache cache - Miss
DEBUG [EhCache]  Element for person is null
DEBUG [StandardQueryCache]  returning cached query results
DEBUG [JDBCContext]  after autocommit
DEBUG [ConnectionManager]  aggressively releasing JDBC connection
DEBUG [SessionImpl]  after transaction completion
DEBUG [DefaultSaveOrUpdateEventListener]  saving transient instance
DEBUG [IncrementGenerator]  fetching initial value: select max(id) from person
DEBUG [AbstractBatcher]  about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG [ConnectionManager]  opening JDBC connection
DEBUG [DriverManagerConnectionProvider]  total checked-out connections: 0
DEBUG [DriverManagerConnectionProvider]  using pooled JDBC connection, pool size: 0
DEBUG [SQL]  select max(id) from person
Hibernate: select max(id) from person
DEBUG [AbstractBatcher]  preparing statement
DEBUG [IncrementGenerator]  first free id: 1
DEBUG [AbstractBatcher]  about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG [AbstractBatcher]  closing statement
DEBUG [AbstractSaveEventListener]  generated identifier: 1, using strategy: org.hibernate.id.IncrementGenerator
DEBUG [AbstractSaveEventListener]  saving [org.gbif.model.Person#1]
DEBUG [QueryPlanCache]  located HQL query plan in cache (from Person p where p.name=? )
DEBUG [QueryPlanCache]  located HQL query plan in cache (from Person p where p.name=? )
DEBUG [AbstractFlushingEventListener]  flushing session
DEBUG [AbstractFlushingEventListener]  processing flush-time cascades
DEBUG [AbstractFlushingEventListener]  dirty checking collections
DEBUG [AbstractFlushingEventListener]  Flushing entities and processing referenced collections
DEBUG [AbstractFlushingEventListener]  Processing unreferenced collections
DEBUG [AbstractFlushingEventListener]  Scheduling collection removes/(re)creates/updates
DEBUG [AbstractFlushingEventListener]  Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
DEBUG [AbstractFlushingEventListener]  Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
DEBUG [Printer]  listing entities:
DEBUG [Printer]  org.gbif.model.Person{name=Tom, id=1}
DEBUG [ActionQueue]  changes must be flushed to space: person
DEBUG [DefaultAutoFlushEventListener]  Need to execute flush
DEBUG [AbstractFlushingEventListener]  executing flush
DEBUG [ConnectionManager]  registering flush begin
DEBUG [UpdateTimestampsCache]  Pre-invalidating space [person]
DEBUG [Cache]  org.hibernate.cache.UpdateTimestampsCache: Is element with key person expired?: false
DEBUG [AbstractEntityPersister]  Inserting entity: [org.gbif.model.Person#1]
DEBUG [AbstractBatcher]  about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG [SQL]  insert into person (name, id) values (?, ?)
Hibernate: insert into person (name, id) values (?, ?)
DEBUG [AbstractBatcher]  preparing statement
DEBUG [AbstractEntityPersister]  Dehydrating entity: [org.gbif.model.Person#1]
DEBUG [StringType]  binding 'Tom' to parameter: 1
DEBUG [LongType]  binding '1' to parameter: 2
DEBUG [AbstractBatcher]  Adding to batch
DEBUG [AbstractBatcher]  Executing batch size: 1
DEBUG [AbstractBatcher]  about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG [AbstractBatcher]  closing statement
DEBUG [ConnectionManager]  registering flush end
DEBUG [AbstractFlushingEventListener]  post flush
DEBUG [HQLQueryPlan]  find: from Person p where p.name=?
DEBUG [QueryParameters]  parameters: [Tim]
DEBUG [QueryParameters]  named parameters: {}
DEBUG [StandardQueryCache]  checking cached query results in region: org.hibernate.cache.StandardQueryCache
DEBUG [EhCache]  key: sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [MemoryStore]  org.hibernate.cache.StandardQueryCacheCache: MemoryStore hit for sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [Cache]  org.hibernate.cache.StandardQueryCache: Is element with key sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {} expired?: false
DEBUG [StandardQueryCache]  Checking query spaces for up-to-dateness: [person]
DEBUG [EhCache]  key: person
DEBUG [MemoryStore]  org.hibernate.cache.UpdateTimestampsCacheCache: MemoryStore hit for person
DEBUG [Cache]  org.hibernate.cache.UpdateTimestampsCache: Is element with key person expired?: false
DEBUG [UpdateTimestampsCache]  [person] last update timestamp: 4696662464700416, result set timestamp: 4696662217216000
DEBUG [StandardQueryCache]  cached query results were not up to date
DEBUG [AbstractBatcher]  about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG [SQL]  select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
Hibernate: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
DEBUG [AbstractBatcher]  preparing statement
DEBUG [StringType]  binding 'Tim' to parameter: 1
DEBUG [AbstractBatcher]  about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG [Loader]  processing result set
DEBUG [Loader]  done processing result set (0 rows)
DEBUG [AbstractBatcher]  about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG [AbstractBatcher]  about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG [AbstractBatcher]  closing statement
DEBUG [Loader]  total objects hydrated: 0
DEBUG [StatefulPersistenceContext]  initializing non-lazy collections
DEBUG [StandardQueryCache]  caching query results in region: org.hibernate.cache.StandardQueryCache
DEBUG [JDBCContext]  after autocommit
DEBUG [ConnectionManager]  aggressively releasing JDBC connection
DEBUG [ConnectionManager]  releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG [DriverManagerConnectionProvider]  returning connection to pool, pool size: 1
DEBUG [QueryPlanCache]  located HQL query plan in cache (from Person p where p.name=? )
DEBUG [QueryPlanCache]  located HQL query plan in cache (from Person p where p.name=? )
DEBUG [AbstractFlushingEventListener]  flushing session
DEBUG [AbstractFlushingEventListener]  processing flush-time cascades
DEBUG [AbstractFlushingEventListener]  dirty checking collections
DEBUG [AbstractFlushingEventListener]  Flushing entities and processing referenced collections
DEBUG [AbstractFlushingEventListener]  Processing unreferenced collections
DEBUG [AbstractFlushingEventListener]  Scheduling collection removes/(re)creates/updates
DEBUG [AbstractFlushingEventListener]  Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
DEBUG [AbstractFlushingEventListener]  Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
DEBUG [Printer]  listing entities:
DEBUG [Printer]  org.gbif.model.Person{name=Tom, id=1}
DEBUG [DefaultAutoFlushEventListener]  Dont need to execute flush
DEBUG [HQLQueryPlan]  find: from Person p where p.name=?
DEBUG [QueryParameters]  parameters: [Tim]
DEBUG [QueryParameters]  named parameters: {}
DEBUG [StandardQueryCache]  checking cached query results in region: org.hibernate.cache.StandardQueryCache
DEBUG [EhCache]  key: sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [MemoryStore]  org.hibernate.cache.StandardQueryCacheCache: MemoryStore hit for sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {}
DEBUG [Cache]  org.hibernate.cache.StandardQueryCache: Is element with key sql: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?; parameters: Tim, ; named parameters: {} expired?: false
DEBUG [StandardQueryCache]  Checking query spaces for up-to-dateness: [person]
DEBUG [EhCache]  key: person
DEBUG [MemoryStore]  org.hibernate.cache.UpdateTimestampsCacheCache: MemoryStore hit for person
DEBUG [Cache]  org.hibernate.cache.UpdateTimestampsCache: Is element with key person expired?: false
DEBUG [UpdateTimestampsCache]  [person] last update timestamp: 4696662464700416, result set timestamp: 4696662217216000
DEBUG [StandardQueryCache]  cached query results were not up to date
DEBUG [AbstractBatcher]  about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG [ConnectionManager]  opening JDBC connection
DEBUG [DriverManagerConnectionProvider]  total checked-out connections: 0
DEBUG [DriverManagerConnectionProvider]  using pooled JDBC connection, pool size: 0
DEBUG [SQL]  select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
Hibernate: select person0_.id as id0_, person0_.name as name0_ from person person0_ where person0_.name=?
DEBUG [AbstractBatcher]  preparing statement
DEBUG [StringType]  binding 'Tim' to parameter: 1
DEBUG [AbstractBatcher]  about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG [Loader]  processing result set
DEBUG [Loader]  done processing result set (0 rows)
DEBUG [AbstractBatcher]  about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG [AbstractBatcher]  about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG [AbstractBatcher]  closing statement
DEBUG [Loader]  total objects hydrated: 0
DEBUG [StatefulPersistenceContext]  initializing non-lazy collections
DEBUG [StandardQueryCache]  caching query results in region: org.hibernate.cache.StandardQueryCache
DEBUG [JDBCContext]  after autocommit
DEBUG [ConnectionManager]  aggressively releasing JDBC connection
DEBUG [ConnectionManager]  releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG [DriverManagerConnectionProvider]  returning connection to pool, pool size: 1
DEBUG [SessionImpl]  closing session
DEBUG [ConnectionManager]  connection already null in cleanup : no action

         String name = "Tim";
         
         // only one SQL statement comes out the logs...
         // cache is working
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();
         
         // create a person
         // the UpdateTimestampsCache will now say that
         // the above query is old
         Person person = new Person();
         person.setName("Tom");
         session.save(person);

         // recreate the session
         HibernateUtil.closeSession();
         session = HibernateUtil.currentSession();
         
         // No queries - hit's the cache
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();
         session.createQuery("from Person p where p.name=? ")
            .setParameter(0, name)
            .setCacheable(true)
            .list();