Ich er­freue mich ge­ra­de an einem JPA/Hi­ber­na­te-Pro­blem, das ent­we­der sehr sub­til ist, oder bei dem ich äu­ßerst un­ge­schickt an­stel­le :-) Je­den­falls möch­te ich die Ge­le­gen­heit nut­zen, ei­ni­ge Hilfs­mit­tel zu sam­meln, mit denen man Hi­ber­na­te „unter die Haube“ gu­cken kann.

Hi­ber­na­te-Log­aus­ga­ben

Hi­ber­na­te kann ver­schie­de­ne Dinge mit­tels log4j mit­pro­to­kol­lie­ren. Bei mir als hilf­reich haben sich er­wie­sen:

Pro­to­kol­lie­ren aller aus­ge­führ­ter SQL-State­ments:

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

Aus­ge­ben des Trans­ak­ti­ons-Sta­tus (Be­ginn und Ende einer Trans­ak­ti­on, sowie In­for­ma­tio­nen über Stel­len, an denen keine Trans­ak­ti­on nötig ist):

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

Ab­fra­ge im Code, ob man sich in einer Trans­ak­ti­on be­fin­det

Ich ver­mu­te­te mein Pro­blem in die­sem Be­reich; mit­tels TransactionAspectSupport.currentTransactionStatus() be­kommt man ver­schie­de­ne Hin­wei­se über den ak­tu­el­len Trans­ak­ti­ons­sta­tus, und mit dem hier ge­zeig­ten Code kann man sich so etwas wie As­ser­ti­ons bauen, wenn ein Code­ab­schnitt ohne be­ste­hen­de Trans­ak­ti­on auf­ge­ru­fen wird.

Ca­che-In­va­li­die­rung

Obige Ver­mu­tun­gen führ­ten immer noch nicht zum Ziel, nächs­ter Ver­dacht war ir­gend­ein Cache. Hier fand ich Hin­wei­se, wie man den JPA-Ca­che in­va­li­diert.

Mein Pro­blem?

Ich lade und spei­che­re Daten mit­tels JPA, an­schlie­ßend muss ich ei­ni­ge Da­ten­ma­ni­pu­la­ti­on per SQL-Be­fehl aus­füh­ren. Die­ses State­ment greift auf die Daten zu, die ich zuvor per JPA ver­än­dert habe - und liest dabei ver­al­te­te Daten (vor der Än­de­rung). Ich dach­te zu­nächst, dass das SQL viel­leicht au­ßer­halb der Trans­ak­ti­on aus­ge­führt wird - dem ist nicht so.

Nun habe ich fest­ge­stellt, dass das Up­date auf mei­nen Daten erst als SQL-State­ment im Log er­scheint, wenn ich einen wei­te­ren Zu­griff (auch nur le­send! Auch per SQL!) mache. Vor­her wer­den meine Än­de­run­gen nicht in die Da­ten­bank ge­schrie­ben, was das „ver­al­te­te-Da­ten“-Phä­no­men er­klärt. Sehr merk­wür­dig.

Letzt­end­lich bin ich auf EntityManager.​flush() ge­sto­ßen. Damit lan­den aus­ste­hen­de Ope­ra­tio­nen in der Da­ten­bank. Wieso ein sol­cher Flush von einem ein­fa­chen SELECT, nicht aber von mei­nem Up­date-State­ment an­ge­sto­ßen wird (und warum das flush nicht pau­schal aus­ge­führt wird, wenn man na­ti­ve SQL macht), ist mir nicht 100%ig ein­sich­tig…

Zu­sätz­lich stell­te sich der Ca­che-Ver­dacht auch als kor­rekt her­aus: Nach einem Up­date via SQL er­hielt ich (zu­min­dest in­ner­halb einer Trans­ak­ti­on) beim Laden eines Ob­jekts ver­al­te­te Daten. Zu­sätz­lich war also nach dem SQL-State­ment ein EntityManager.refresh(…) not­wen­dig.