Burke—
Good point… yes, as it turns out it looks like although the reference is being
changed, the new timestamp is a clone of the old timestamp.
I dug in a little deeper and found something else… reading up on hibernate, it
seems that the saveOrUpdate method should do *nothing* to objects that are
currently persisted within the current session. It only persists new objects
(save) or reattachs objects that have been deattached (update).
This would mean in the second test script (I’ll copy it below for convenience),
the saveEncounter—which calls the underlying saveOrUpdate via the dao--really
shouldn’t do anything.
public void editingExistingEncounter_shouldUpdateDateCreated() throws Exception
{
EncounterService es = Context.getEncounterService();
// First, load an existing Encounter
Encounter enc = Context.getEncounterService().getEncounter(3);
// confirm that the date changed is null
assertNull(enc.getDateChanged());
// Now edit the obs and resave the encounter
for (Obs o : enc.getAllObs()) {
o.setValueNumeric(75d);
}
// resave the encounter
es.saveEncounter(enc);
// PASSES: confirm that the date changed has been set
assertNotNull(enc.getDateChanged());
}
So I did a little more tracing and it turns out that the two flushes that occur
when you call saveEncounter *are not* caused by
sessionFactory.getCurrentSession().saveOrUpdate(encounter); in the dao. The
flushes occur only occur when DAO queries are made during the execution of the
saveEncounter method (they happen during the dao calls made at
EncounterServiceImpl:100 and EncounterServiceImpl:102). So it seems that the
flush that is caused by calling saveEncounter is coincidental and not
intentional.
To test this out further I set out to test a save method that that was simpler
(and therefore might not coincidentially cause a flush) and see if I could get
it to fail.
I took the following unit test:
public void saveEncounterType_shouldUpdateAnExistingEncounterTypeName() throws
Exception {
EncounterService encounterService = Context.getEncounterService();
EncounterType encounterTypeToChange =
encounterService.getEncounterType(1);
// change the name of the type
encounterTypeToChange.setName("another test");
// save the type to the database
encounterService.saveEncounterType(encounterTypeToChange);
// make sure the encounter type id didn't change
assertEquals(1,
encounterTypeToChange.getEncounterTypeId().intValue());
// refetch the encounter type from the database
EncounterType fetchedEncounterType =
encounterService.getEncounterType(1);
assertTrue(fetchedEncounterType.getName().equals("another test"));
}
I traced this test and discovered that an onDirtyFlush is never called during
its execution.
So I tested commenting out the “encounterService.saveEncounterType” line in
the above test, and, as I suspected, the test still passed.
But, if I keep the saveEncounterType method but add a Context.clearSession()
after it *the test fails*.
My conclusion here is that in this test the change is never committed to the
database (of course we are dealing with a mock db, which may affect things),
and the only reason the test passes is because hibernate checks its internal
session cache when refetching the encounter. Is this known behavior that I
didn’t completely understand, or have we all been missing this?
Mark
From: [email protected] [mailto:[email protected]] On Behalf Of Burke Mamlin
Sent: Monday, November 28, 2011 9:34 AM
To: [email protected]
Subject: Re: [OPENMRS-DEV] Auditable Interceptor functionality
Mark,
Thanks so much for this investigating. It was a perfect addition to a plate of
turkey and a glass of Australian shiraz. :-)
At the end, when you say "it is odd that dateCreated is being changed", you
mean that the dateCreated reference has changed, not the value, right?
Presumably because hibernate is doing some cloning or similar trickery under
the hood?
-Burke
On Thu, Nov 24, 2011 at 9:39 AM, Mark Goodrich
<[email protected]<mailto:[email protected]>> wrote:
No, even after flushing the session, the assert still fails.
There's only one intercepted method in the AuditableInterceptor... the
onDirtyFlush. The interceptor methods are called on an object-by-object basis.
I added a dummy onSave method to the interceptor and debugged and found the
following:
1 )After the first saveEncounter in the editNewEncounter method:
The onSave method is called three times, once for the Encounter, and once for
each of the two Obs added
The onDirtyFlush method is not called
2) After the second saveEncounter in the editNewEncounter method:
The onDirtyFlush method is called four times, twice for each of the two edited
Obs
The onSave method is not callled
3) After the only saveEncounter in the editExistingEncounter method:
The onDirtyFlush method is called six times, twice for the Encounter, and twice
for the two edited Obs
The onSave method is not called
I looked a little deeper into #3 to see exactly why the onDirtyFlush method was
being called to hopefully determine why it wasn't being called in case #2.
First, during the saveEncounter in the editExisingEncounter method,
onDirtyFlush is called with the Encounter, because three encounter fields have
changing:
encounterDate and dateCreated are both changing from an existing timestamp
object to a new timestamp object
voidReason is changing from and empty string to null
Next, onDirtyFlush is called for each of the two Obs, with the following fields
changing:
obsDatetime and dateCreated are both changing from an existing timestamp object
to a new timestamp object
the valueNumeric is updated, as expected
the personId is updated from one Integer object to another Integer object
(though with the same integer value, thankfully!)
Next, onDirtyFlush is called again with the Encounter. Now, six fields have
changed... the three fields mentioned previous (encounterDate, dateCreated, and
voidReason) all have the same previous and current values as when the last
dirty flush was called, and three new fields have changed:
voided from null to false
dateChanged from null to a timestamp
changedBy from null to the current user
(So it looks like this caused by the voided value change, or it is a recursive
call caused by the changes made in the AuditableInterceptor itself.)
Then, finally, onDirtyFlush is called again with the two obs, and checking the
current previous states show the exact same changes as the first call.
I don't know if I can come to any conclusions here except that it is odd that
dateCreated is being changed. One tangential point is that when obs are
updated this way (saved via a cascade from an encounter) they are not voided
and recreated, but I believe this is a known issue I entered a ticket about at
some point?
I hope I've provided you all with some fun Thanksgiving reading.
Mark
________________________________________
From: [email protected]<mailto:[email protected]>
[[email protected]<mailto:[email protected]>] On Behalf Of Ben Wolfe
[[email protected]<mailto:[email protected]>]
Sent: Thursday, November 24, 2011 7:40 AM
To:
[email protected]<mailto:[email protected]>
Subject: Re: [OPENMRS-DEV] Auditable Interceptor functionality
Do you know which method in the interceptor is called on that first save?
Is the dateChanged set at the end of the transaction? If you flush the session
right before your failing assert, does the assert then pass?
Ben
On Thu, Nov 24, 2011 at 12:22 AM, Mark Goodrich
<[email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>>>
wrote:
Sorry I missed the design call on hibernate interceptors today, but,
coincidentally, I was investigating an issue with the Auditable interceptor
that I uncovered when running the HFE unit tests against 1.8. Or, rather,
something that may be an issue.
Take the following unit test, which creates a new encounter, saves it, updates
the obs associated with it, and saves it again. Using the old save handlers,
the dateChanged of the encounter would be set upon the second save. But, with
the hibernate interceptor, this is not the case and so this test will fail:
public void editingNewEncounter_shouldUpdateDateCreated() throws Exception {
EncounterService es = Context.getEncounterService();
// First, create a new Encounter
Encounter enc = new Encounter();
enc.setLocation(new Location(1));
enc.setEncounterType(new EncounterType(1));
enc.setEncounterDatetime(new Date());
enc.setPatient(new Patient(3));
enc.setProvider(new Person(1));
// Now add a couple obs to it
Obs newObs = new Obs();
newObs.setConcept(new Concept(1));
newObs.setValueNumeric(50d);
enc.addObs(newObs);
Obs anotherNewObs = new Obs();
anotherNewObs.setConcept(new Concept(1));
anotherNewObs.setValueNumeric(100d);
enc.addObs(anotherNewObs);
// now save the encounter
es.saveEncounter(enc);
// flush the session, just to be safe
Context.flushSession();
// confirm that the encounter has been assigned an id, but the
date changed is still null
assertNotNull(enc.getId());
assertNull(enc.getDateChanged());
// confirm tha the obs have been added to the encounter
assertEquals(2, enc.getAllObs().size());
// Now edit the obs and resave the encounter
for (Obs o : enc.getAllObs()) {
o.setValueNumeric(75d);
}
// resave the encounter
es.saveEncounter(enc);
// FAILS: confirm that the date changed has been set
assertNotNull(enc.getDateChanged());
}
Note, however, that if I load an existing encounter and update the obs, the
date changed will be set:
public void editingExistingEncounter_shouldUpdateDateCreated() throws Exception
{
EncounterService es = Context.getEncounterService();
// First, load an existing Encounter
Encounter enc = Context.getEncounterService().getEncounter(3);
// confirm that the date changed is null
assertNull(enc.getDateChanged());
// Now edit the obs and resave the encounter
for (Obs o : enc.getAllObs()) {
o.setValueNumeric(75d);
}
// resave the encounter
es.saveEncounter(enc);
// PASSES: confirm that the date changed has been set
assertNotNull(enc.getDateChanged());
}
In the first case the encounter is never passed to the interceptor onDirtyFlush
method... I would assume because the Encounter is still in the new/save state?
Is this a problem? This is a contrived case, and it seems to make sense that
if an encounter is saved twice in rapid succession it's date changed isn't
set--but this isn't the behavior I would have expected, and it is different
from how the old save handlers worked.
Thoughts?
Mark
_________________________________________
To unsubscribe from OpenMRS Developers' mailing list, send an e-mail to
[email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>>
with "SIGNOFF openmrs-devel-l" in the body (not the subject) of your e-mail.
[mailto:[email protected]<mailto:[email protected]><mailto:[email protected]<mailto:[email protected]>>?body=SIGNOFF%20openmrs-devel-l]
________________________________
Click here to
unsubscribe<mailto:[email protected]<mailto:[email protected]>?body=SIGNOFF%20openmrs-devel-l>
from OpenMRS Developers' mailing list
_________________________________________
To unsubscribe from OpenMRS Developers' mailing list, send an e-mail to
[email protected]<mailto:[email protected]> with "SIGNOFF
openmrs-devel-l" in the body (not the subject) of your e-mail.
[mailto:[email protected]<mailto:[email protected]>?body=SIGNOFF%20openmrs-devel-l]
________________________________
Click here to
unsubscribe<mailto:[email protected]?body=SIGNOFF%20openmrs-devel-l>
from OpenMRS Developers' mailing list
