Ich erfreue mich gerade an einem JPA/Hibernate-Problem, das entweder sehr subtil ist, oder bei dem ich äußerst ungeschickt anstelle :-) Jedenfalls möchte ich die Gelegenheit nutzen, einige Hilfsmittel zu sammeln, mit denen man Hibernate „unter die Haube“ gucken kann.

Hibernate-Logausgaben

Hibernate kann verschiedene Dinge mittels log4j mitprotokollieren. Bei mir als hilfreich haben sich erwiesen:

Protokollieren aller ausgeführter SQL-Statements:

<logger name="org.hibernate.SQL">
    <level value="debug"/>
</logger>

Ausgeben des Transaktions-Status (Beginn und Ende einer Transaktion, sowie Informationen über Stellen, an denen keine Transaktion nötig ist):

<logger name="org.springframework.transaction.interceptor">
    <level value="trace" />
</logger>

Abfrage im Code, ob man sich in einer Transaktion befindet

Ich vermutete mein Problem in diesem Bereich; mittels TransactionAspectSupport.currentTransactionStatus() bekommt man verschiedene Hinweise über den aktuellen Transaktionsstatus, und mit dem hier gezeigten Code kann man sich so etwas wie Assertions bauen, wenn ein Codeabschnitt ohne bestehende Transaktion aufgerufen wird.

Cache-Invalidierung

Obige Vermutungen führten immer noch nicht zum Ziel, nächster Verdacht war irgendein Cache. Hier fand ich Hinweise, wie man den JPA-Cache invalidiert.

Mein Problem?

Ich lade und speichere Daten mittels JPA, anschließend muss ich einige Datenmanipulation per SQL-Befehl ausführen. Dieses Statement greift auf die Daten zu, die ich zuvor per JPA verändert habe - und liest dabei veraltete Daten (vor der Änderung). Ich dachte zunächst, dass das SQL vielleicht außerhalb der Transaktion ausgeführt wird - dem ist nicht so.

Nun habe ich festgestellt, dass das Update auf meinen Daten erst als SQL-Statement im Log erscheint, wenn ich einen weiteren Zugriff (auch nur lesend! Auch per SQL!) mache. Vorher werden meine Änderungen nicht in die Datenbank geschrieben, was das „veraltete-Daten“-Phänomen erklärt. Sehr merkwürdig.

Letztendlich bin ich auf EntityManager.flush() gestoßen. Damit landen ausstehende Operationen in der Datenbank. Wieso ein solcher Flush von einem einfachen SELECT, nicht aber von meinem Update-Statement angestoßen wird (und warum das flush nicht pauschal ausgeführt wird, wenn man native SQL macht), ist mir nicht 100%ig einsichtig…

Zusätzlich stellte sich der Cache-Verdacht auch als korrekt heraus: Nach einem Update via SQL erhielt ich (zumindest innerhalb einer Transaktion) beim Laden eines Objekts veraltete Daten. Zusätzlich war also nach dem SQL-Statement ein EntityManager.refresh(…) notwendig.