Manipulating Database Outside Hibernate And Caching Problem

postop · **Posted:** Tue Mar 02, 2004 3:13 pm

Read through the forums and found a bunch of places saying that:
1. You cannot disable the second level cache by excluding it from the hibernate.cfg.xml, Hibernate will use EHCache by default.
2. If you manage your Sessions correctly and flush, close, and disconnect them at the appropriate times, you won't run into any problems with the session level cache.
3. If you do not specify a caching scheme in the mapping file, your objects will not be stored in the second leve cache.

If that's correct, then why am I having this problem:

I have one web application that acts as a simple database viewer. There is only one table and it's just for events (see mapping below for details). There are other applications outside the web application that manipulate this database and add more events of their own.

The web application pages results and I have to do two queries when displaying a single page.

Query 1 gets the total number of rows

Code:

String className = obj.getClass().getName();
List countList = session.find("select count(obj) from " + className + " as obj");
int count = ((Integer)countList.iterator().next()).intValue();

Query 2 uses that number to get all the rows for that page

Code:

Criteria c = session.createCriteria(Event.class);
c.add(Example.create(obj));
c.setMaxResults(resultSize);
c.setFirstResult(resultSize * (pageNumber -1));         
List events = c.list();

The paging works fine and if any rows are added to the table through the web app, they come up when I need to display them. But when I add a row outside of the web app (via manual SQL) and try to view it, the web app won't find it. I've stepped through the code and it will only see the same rows since it either started or it added a row.

This sounds like a caching issue but I'm not sure where to fix it. I'm not re-using my session and I'm always closing it after every hit to the database. I'm not specifying any chaching in the mapping file. I've tried to evict the objects from the session facotry to test this but it either wasn't doing it right or it wasn't working. I thought it might be query caching but when I try to view a specifc event by the new id, it still won't find it.

Any ideas?

Versions:
Hibernate 2.1.2
MySQL 4.0.18

Mapping:

Code:

<hibernate-mapping>
   <class name="model.event.Event" table="event" discriminator-value="0">
        <id name="id">
            <generator class="native"/>
        </id>
        <discriminator column="type" type="int"  not-null="true"/>        
        <property name="message" not-null="true"/>
        <property name="date" not-null="true"/>         
        <subclass name="model.event.impl.GenericEvent" discriminator-value="1"/>
   </class>

anthony · **Posted:** Tue Mar 02, 2004 3:18 pm

hum,
are you sure :
- the external changes are comitted?
- you are using another hibernate session?

anthony · **Posted:** Tue Mar 02, 2004 3:21 pm

just a little test:
1- launch your app, add, load objects
2- insert rows outside the app
3- here, you're saying the app doesn't see the inserted rows
4- so stop start your app and test again

if your app still does not see the changes, your external insert has not been comitted

postop · **Posted:** Tue Mar 02, 2004 3:37 pm

Acutally, all the external manipulation that I'm doing is handwritten SQL through MySQL control center. As far as I know, there is no option to commit/rollback like TOAD. Everything you do goes right in.

If I restart the application after the row is inserted it will see it. It will only work correctly on the first page load or when it uses hibernate insert it's own row.

anthony · **Posted:** Tue Mar 02, 2004 3:41 pm

strange....
have you tried session.clear() before querying? if you're sure you session management is ok, it is not necessary, but if you doubt it might be a good test.
Are you developping under eclipse? jbuilder? by debugging, is the query result list incomplete too?

postop · **Posted:** Tue Mar 02, 2004 3:50 pm

I'm using eclipse 3.0M7. When I step through the code it will always maintain the previous state (total number of rows and the row data) even if data is added or removed from the database.

I tried putting in session.clear() before I do my thing but it's still behaving the same way.

I've turned debug on for everything and I'm showing the SQL. I'm not sure what to look for if it's pulling it from a cache, but there is a bunch of SQL being generated and it looks like it's hitting the database.

anthony · **Posted:** Tue Mar 02, 2004 3:58 pm

if i remember, only iterate() method hits the cache, you're are using the list() method, so it seems it can't be a cache problem...

if the generated sql is not too long, try copy/paste it into a db client to see if your new rows are returned

postop · **Posted:** Tue Mar 02, 2004 4:13 pm

Sorry, it's kinda long, but I seperated each step that I took.

###############
#Inserting 1 row into a clean table
###############
14:07:16,755 DEBUG SessionImpl:528 - opened session
14:07:16,771 DEBUG JDBCTransaction:37 - begin
14:07:16,771 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 0
14:07:16,771 DEBUG DriverManagerConnectionProvider:84 - using pooled JDBC connection, pool size: 0
14:07:16,786 DEBUG JDBCTransaction:41 - current autocommit status:false
14:07:16,802 DEBUG SessionImpl:786 - saving [ercot.model.event.impl.GenericEvent#<null>]
14:07:16,802 DEBUG EntityPersister:491 - Inserting entity: ercot.model.event.impl.GenericEvent (native id)
14:07:16,802 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets
14:07:16,802 DEBUG SQL:223 - insert into event (message, date, type) values (?, ?, 1)
Hibernate: insert into event (message, date, type) values (?, ?, 1)
14:07:16,802 DEBUG BatcherImpl:227 - preparing statement
14:07:16,833 DEBUG EntityPersister:389 - Dehydrating entity: [ercot.model.event.impl.GenericEvent#<null>]
14:07:16,865 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets
14:07:16,865 DEBUG BatcherImpl:240 - closing statement
14:07:16,865 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets
14:07:16,865 DEBUG SQL:223 - SELECT LAST_INSERT_ID()
Hibernate: SELECT LAST_INSERT_ID()
14:07:16,865 DEBUG BatcherImpl:227 - preparing statement
14:07:16,865 DEBUG EntityPersister:528 - Natively generated identity: 55
14:07:16,865 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets
14:07:16,880 DEBUG BatcherImpl:240 - closing statement
14:07:16,896 DEBUG JDBCTransaction:59 - commit
14:07:16,896 DEBUG SessionImpl:2193 - flushing session
14:07:16,911 DEBUG SessionImpl:2321 - Flushing entities and processing referenced collections
14:07:16,911 DEBUG SessionImpl:2664 - Processing unreferenced collections
14:07:16,927 DEBUG SessionImpl:2678 - Scheduling collection removes/(re)creates/updates
14:07:16,927 DEBUG SessionImpl:2217 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
14:07:16,927 DEBUG SessionImpl:2222 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
14:07:16,943 DEBUG Printer:75 - listing entities:
14:07:16,943 DEBUG Printer:82 - ercot.model.event.impl.GenericEvent{message=First Message, date=02 March 2004 14:07:16, id=55}
14:07:16,943 DEBUG SessionImpl:2258 - executing flush
14:07:16,943 DEBUG SessionImpl:2708 - post flush
14:07:16,989 DEBUG SessionImpl:558 - transaction completion

#########
#Viewing page one of all rows
#########

14:07:49,416 DEBUG SessionImpl:528 - opened session
14:07:49,432 DEBUG SessionImpl:1460 - find: select count(obj) from ercot.model.event.impl.GenericEvent as obj
14:07:49,479 DEBUG QueryTranslator:147 - compiling query
14:07:49,557 DEBUG SessionImpl:2193 - flushing session
14:07:49,557 DEBUG SessionImpl:2321 - Flushing entities and processing referenced collections
14:07:49,573 DEBUG SessionImpl:2664 - Processing unreferenced collections
14:07:49,573 DEBUG SessionImpl:2678 - Scheduling collection removes/(re)creates/updates
14:07:49,573 DEBUG SessionImpl:2217 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
14:07:49,573 DEBUG SessionImpl:2222 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
14:07:49,573 DEBUG SessionImpl:1745 - Dont need to execute flush
14:07:49,573 DEBUG QueryTranslator:199 - HQL: select count(obj) from ercot.model.event.impl.GenericEvent as obj
14:07:49,588 DEBUG QueryTranslator:200 - SQL: select count(genericeve0_.id) as x0_0_ from event genericeve0_ where genericeve0_.type=1
14:07:49,588 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets
14:07:49,588 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 1
14:07:49,588 DEBUG DriverManagerConnectionProvider:94 - opening new JDBC connection
14:07:49,619 DEBUG DriverManagerConnectionProvider:100 - created connection to: jdbc:mysql://localhost/ercot-event, Isolation Level: 4
14:07:49,619 DEBUG SQL:223 - select count(genericeve0_.id) as x0_0_ from event genericeve0_ where genericeve0_.type=1
Hibernate: select count(genericeve0_.id) as x0_0_ from event genericeve0_ where genericeve0_.type=1
14:07:49,619 DEBUG BatcherImpl:227 - preparing statement
14:07:49,619 DEBUG Loader:196 - processing result set
14:07:49,619 DEBUG Loader:404 - result row:
14:07:49,635 DEBUG Loader:225 - done processing result set (1 rows)
14:07:49,635 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets
14:07:49,635 DEBUG BatcherImpl:240 - closing statement
14:07:49,635 DEBUG SessionImpl:3000 - initializing non-lazy collections
14:07:49,744 DEBUG SessionImpl:3431 - find by criteria: [net.sf.hibernate.impl.CriteriaImpl$CriterionEntry@1f7dbd8]
14:07:49,760 DEBUG SessionImpl:2193 - flushing session
14:07:49,760 DEBUG SessionImpl:2321 - Flushing entities and processing referenced collections
14:07:49,776 DEBUG SessionImpl:2664 - Processing unreferenced collections
14:07:49,776 DEBUG SessionImpl:2678 - Scheduling collection removes/(re)creates/updates
14:07:49,776 DEBUG SessionImpl:2217 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
14:07:49,776 DEBUG SessionImpl:2222 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
14:07:49,776 DEBUG SessionImpl:1745 - Dont need to execute flush
14:07:49,791 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets
14:07:49,791 DEBUG SQL:223 - select this.id as id0_, this.type as type0_, this.message as message0_, this.date as date0_ from event this where (1=1) limit ?
Hibernate: select this.id as id0_, this.type as type0_, this.message as message0_, this.date as date0_ from event this where (1=1) limit ?
14:07:49,791 DEBUG BatcherImpl:227 - preparing statement
14:07:49,807 DEBUG Loader:196 - processing result set
14:07:49,807 DEBUG Loader:404 - result row: 55
14:07:49,807 DEBUG Loader:535 - Initializing object from ResultSet: 55
14:07:49,807 DEBUG Loader:604 - Hydrating entity: ercot.model.event.impl.GenericEvent#55
14:07:49,838 DEBUG Loader:225 - done processing result set (1 rows)
14:07:49,838 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets
14:07:49,838 DEBUG BatcherImpl:240 - closing statement
14:07:49,838 DEBUG Loader:238 - total objects hydrated: 1
14:07:49,869 DEBUG SessionImpl:2129 - resolving associations for [ercot.model.event.impl.GenericEvent#55]
14:07:49,869 DEBUG SessionImpl:2153 - done materializing entity [ercot.model.event.impl.GenericEvent#55]
14:07:49,869 DEBUG SessionImpl:3000 - initializing non-lazy collections
14:07:49,869 DEBUG SessionImpl:2193 - flushing session
14:07:49,869 DEBUG SessionImpl:2321 - Flushing entities and processing referenced collections
14:07:49,885 DEBUG SessionImpl:2664 - Processing unreferenced collections
14:07:49,885 DEBUG SessionImpl:2678 - Scheduling collection removes/(re)creates/updates
14:07:49,885 DEBUG SessionImpl:2217 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
14:07:49,885 DEBUG SessionImpl:2222 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
14:07:49,885 DEBUG Printer:75 - listing entities:
14:07:49,901 DEBUG Printer:82 - ercot.model.event.impl.GenericEvent{message=First Message, date=02 March 2004 14:07:16, id=55}
14:07:49,901 DEBUG SessionImpl:2258 - executing flush
14:07:49,901 DEBUG SessionImpl:2708 - post flush
14:07:49,901 DEBUG SessionImpl:3187 - disconnecting session
14:07:49,916 DEBUG DriverManagerConnectionProvider:114 - returning connection to pool, pool size: 1
14:07:49,916 DEBUG SessionImpl:558 - transaction completion

###
#This was the sql that was run to insert an extra row outside of hibernate
###
insert into `event` (type, message, date) VALUES (1, 'External Message' , '2004-03-02 00:00:00')

###
# Displaying page 1 again will only display the first row
###
14:10:28,068 DEBUG SessionImpl:528 - opened session
14:10:28,068 DEBUG SessionImpl:1460 - find: select count(obj) from ercot.model.event.impl.GenericEvent as obj
14:10:28,068 DEBUG SessionImpl:2193 - flushing session
14:10:28,068 DEBUG SessionImpl:2321 - Flushing entities and processing referenced collections
14:10:28,068 DEBUG SessionImpl:2664 - Processing unreferenced collections
14:10:28,068 DEBUG SessionImpl:2678 - Scheduling collection removes/(re)creates/updates
14:10:28,083 DEBUG SessionImpl:2217 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
14:10:28,083 DEBUG SessionImpl:2222 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
14:10:28,083 DEBUG SessionImpl:1745 - Dont need to execute flush
14:10:28,083 DEBUG QueryTranslator:199 - HQL: select count(obj) from ercot.model.event.impl.GenericEvent as obj
14:10:28,083 DEBUG QueryTranslator:200 - SQL: select count(genericeve0_.id) as x0_0_ from event genericeve0_ where genericeve0_.type=1
14:10:28,083 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets
14:10:28,083 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 1
14:10:28,083 DEBUG DriverManagerConnectionProvider:84 - using pooled JDBC connection, pool size: 0
14:10:28,099 DEBUG SQL:223 - select count(genericeve0_.id) as x0_0_ from event genericeve0_ where genericeve0_.type=1
Hibernate: select count(genericeve0_.id) as x0_0_ from event genericeve0_ where genericeve0_.type=1
14:10:28,099 DEBUG BatcherImpl:227 - preparing statement
14:10:28,099 DEBUG Loader:196 - processing result set
14:10:28,099 DEBUG Loader:404 - result row:
14:10:28,099 DEBUG Loader:225 - done processing result set (1 rows)
14:10:28,099 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets
14:10:28,099 DEBUG BatcherImpl:240 - closing statement
14:10:28,115 DEBUG SessionImpl:3000 - initializing non-lazy collections
14:10:28,115 DEBUG SessionImpl:3431 - find by criteria: [net.sf.hibernate.impl.CriteriaImpl$CriterionEntry@e64795]
14:10:28,115 DEBUG SessionImpl:2193 - flushing session
14:10:28,115 DEBUG SessionImpl:2321 - Flushing entities and processing referenced collections
14:10:28,115 DEBUG SessionImpl:2664 - Processing unreferenced collections
14:10:28,115 DEBUG SessionImpl:2678 - Scheduling collection removes/(re)creates/updates
14:10:28,130 DEBUG SessionImpl:2217 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
14:10:28,130 DEBUG SessionImpl:2222 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
14:10:28,130 DEBUG SessionImpl:1745 - Dont need to execute flush
14:10:28,130 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets
14:10:28,130 DEBUG SQL:223 - select this.id as id0_, this.type as type0_, this.message as message0_, this.date as date0_ from event this where (1=1) limit ?
Hibernate: select this.id as id0_, this.type as type0_, this.message as message0_, this.date as date0_ from event this where (1=1) limit ?
14:10:28,130 DEBUG BatcherImpl:227 - preparing statement
14:10:28,130 DEBUG Loader:196 - processing result set
14:10:28,130 DEBUG Loader:404 - result row: 55
14:10:28,146 DEBUG Loader:535 - Initializing object from ResultSet: 55
14:10:28,146 DEBUG Loader:604 - Hydrating entity: ercot.model.event.impl.GenericEvent#55
14:10:28,146 DEBUG Loader:225 - done processing result set (1 rows)
14:10:28,146 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets
14:10:28,146 DEBUG BatcherImpl:240 - closing statement
14:10:28,146 DEBUG Loader:238 - total objects hydrated: 1
14:10:28,146 DEBUG SessionImpl:2129 - resolving associations for [ercot.model.event.impl.GenericEvent#55]
14:10:28,161 DEBUG SessionImpl:2153 - done materializing entity [ercot.model.event.impl.GenericEvent#55]
14:10:28,177 DEBUG SessionImpl:3000 - initializing non-lazy collections
14:10:28,177 DEBUG SessionImpl:2193 - flushing session
14:10:28,177 DEBUG SessionImpl:2321 - Flushing entities and processing referenced collections
14:10:28,177 DEBUG SessionImpl:2664 - Processing unreferenced collections
14:10:28,177 DEBUG SessionImpl:2678 - Scheduling collection removes/(re)creates/updates
14:10:28,177 DEBUG SessionImpl:2217 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
14:10:28,177 DEBUG SessionImpl:2222 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
14:10:28,193 DEBUG Printer:75 - listing entities:
14:10:28,193 DEBUG Printer:82 - ercot.model.event.impl.GenericEvent{message=First Message, date=02 March 2004 14:07:16, id=55}
14:10:28,193 DEBUG SessionImpl:2258 - executing flush
14:10:28,193 DEBUG SessionImpl:2708 - post flush
14:10:28,193 DEBUG SessionImpl:3187 - disconnecting session
14:10:28,193 DEBUG DriverManagerConnectionProvider:114 - returning connection to pool, pool size: 1
14:10:28,193 DEBUG SessionImpl:558 - transaction completion

anthony · **Posted:** Tue Mar 02, 2004 4:25 pm

how do you obtain the session?
do you commit / close it ?

postop · **Posted:** Tue Mar 02, 2004 4:32 pm

I get the session from the session factory:

Code:

sessionFactory.openSession()

As for closing it, I've was doing

Code:

session.close();

but then I read that you should always disconnect it so I switched it to

Code:

session.disconnect();

Right now it's

Code:

session.flush();
session.clear();
session.disconnect();

right before the catch and return. Not sure the flush or clear are doing anything though.

anthony · **Posted:** Tue Mar 02, 2004 4:44 pm

consider using threadlocal http://www.hibernate.org/43.html

session.flush();
session.connection.commit();
session.disconnect();

anthony · **Posted:** Tue Mar 02, 2004 4:48 pm

sess = sf.openSession();
Transaction tx = sess.beginTransaction();
... query ...
tx.commit(); //flush occurs

you can delete session.clear() line; it was just for a test

Frank Grimes · **Joined:** Fri Apr 22, 2005 4:20 pm **Posts:** 2

i have a similar setup to the one described in the original post and i am having the exact same problem as described there. i don't see a resolution in this topic nor do i find anything in Jira about this issue.

My first thought was that it was a query caching issue, but i've set:
hibernate.cache.use_query_cache false
in my hibernate.properties file as well as called:
Query q = hbmSession.createQuery(query);
q.setCacheMode(CacheMode.REFRESH);
q.setCacheable(false);

i can see edits to the DB from hibernate, but only the ones that were made through hibernate. When i make a change outside of hibernate, my queries never pick up the changes. Specifically, i use hibernate to set a column to '1'. Then in another process
i set the column to '2'. Wheni issue a hibernate query for all rows with column equal to
'2' i don't see the changes made in the separate process. If i use the command line
query tool (i'm using mysql) i can see the rows do in fact have a column value of '2'.

Here's one more, if i shutdown tomcat and restart it, the first query hibernate issues
picks up the changes. i've tried issuing flush() and clear() on the session but it
doesnt' seem to make a difference:
Session hbmSession = ThreadLocalSession.getSession();
hbmSession.flush();
hbmSession.clear();

Anyone have a suggestion? (or is this topic too old to have a new post noticed?)

Geoff2010 · **Joined:** Fri Apr 22, 2005 5:58 pm **Posts:** 26

Funny this topic should be brought up again, as I just came across the same exact issue.

I have a thread which starts up and goes into a while(true){} loop polling a database table for work to do. Any changes that this thread makes can be seen by the query, but anything outside, either external to Hibernate or even a seperate thread/session can't be seen.

I know it is not a DB commit issue because as soon as I stop/start my application it picks up the changes. I have tried every combination of Session.setCacheMode() and Query.setCacheMode() and nothing seems to work...

Any input would be greatly appreciated.
Thanks.
Geoff

Frank Grimes · **Joined:** Fri Apr 22, 2005 4:20 pm **Posts:** 2

Ok, i got this working now. i did several things all at once so i'm not sure exactly what did the trick, but i think what happened was that at one point in my thread i was re-using a Session. Even though i was calling clear/flush on the Session, it didn't notice outside changes to the table. However, when i corrected the situation and called Session.disconnect() and Session.close() for every transaction, my queries started picking up the changes i was making outside of the JVM using Hibernate. So i can confirm that this does work.