Hibernált dátumok és nyáridő

Egy pár hete, a kódbázisban történő kutatgatás, debugolás közben lettem figyelmes arra, hogy valami nem stimmel.

Az alapfelállás:

  • MySQL adatbázis
    • A minket érdeklő dátum Date-ként van tárolva
    • Dockerben fut
    • MySQL-ben lekérdezve SYSTEM timezone-t használ
  • Java alkalmazás
    • A dátum LocalDate-ként van tárolva
    • Ezekből (mivel több is van belőlük) YearWeek konverziót hajtunk végre: a dátum az év melyik hetére esik
    • Ezeket egy Set-ben tároljuk, mert nem számítunk (és nem is szabad hogy legyen) duplikátum(ra)

A probléma ott kezdődött, hogy random futtatásokkor lokálisan vagy 5 értéket tartalmazott a Set (ez a helyes), vagy csak 4-et (nem helyes). Futás közben nem változott, de a program újraindításakor random vagy jó volt, vagy nem.

Fontos, hogy nem állandóan volt reprodukálható a hiba, néha jó volt, néha nem. Több gépen (Windows + macOS) is kipróbáltuk, és azokon is random időközönként vagy helyes, vagy helytelen volt a Set tartalma.

Mivel ez zavaró, de nem ez volt a fő feladat, amiért elkezdtem kutakodni, úgy voltunk vele, hogy majd szemmel tartjuk. De mivel pont azzal a kódrészlettel dolgozunk ebben a negyedévben, amelyikben ez probléma, ezért tegnap elkezdtem mélyebben is utánanézni.

Azt már korábban sikerült kideríteni, hogy néha egy-egy dátum valamiért ugyanarra a hétre esik, mint egy másik, tehát a YearWeek konverzió ugyanarra a (pl. "202414") stringre konvertálja, így a Set kihajítja az egyiket, mert duplikátum.

Oké, de miért van ez?

------

Kiderült, hogy néha a dátum egy nappal korábbra datálódik, mint kellene, azaz "2024-08-26"-ból "2024-08-25" lesz (hétfőből vasárnap). Ha az előző dátum egy héttel előbbre esik, és az a rendes értékével van jelen a konverziókor, akkor ugyanarra a hétre esik mindkettő, és lásd fentebb a Set problémáját. A dolgot komplikálandó, nem minden dátum volt érintett, 15-ből 5 változott. Konzisztensen ugyanazok, de random időközönként.

Itt már azért kicsit összevontam a szemöldököm, mert az adatbázisban még mindig jók voltak az adatok. Nem értettem miért változgatnak 1 napot ugyanazok a dátumok de random módon.

Szóval nekiálltam megnézni, hogy honnan jön a konfig. Mivel ez egy nagy, monolit alkalmazás (másik csapat épp mostanában fejezi majd be a széttördelését), és mivel Java, ezért irgalmatlan sok abszrakción keresztül eljutottam oda, hogy már az adatbázisból való kiolvasáskor is rosszak az adatok. Néha. Tehát azt, hogy az alkalmazás csinálna valami vicceset az adatokkal a betöltés és a felhasználás között, azt ki lehet zárni.

-------

Nosza, akkor, kezdjük el debugolni Hibernate-et, nézzük meg mit csinál. Log level Trace-re, aztán hadd szóljon.

Normál esetben ilyet kapok vissza az adatbázisból:

TRACE o.h.p.entity.AbstractEntityPersister - Hydrating entity: [com.acme.configuration.model.VeryImportantDate#140]
TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([field_name_] : [TIMESTAMP]) - [2025-03-31 00:00:00.0]
DEBUG o.h.t.d.c.AttributeConverterSqlTypeDescriptorAdapter - Converted value on extraction: 2025-03-31 00:00:00.0 -> 2025-03-31

Ez korrekt, mármint azon kívül, hogy az adatbázisban is és a kódban is Date típust használunk, szóval nem tudom honnan szedte a Hibernate azt a TIMESTAMP-et. De legalább a dátum stimmel.

Viszont amikor néha úgy gondolja, akkor ilyet ad vissza:

TRACE o.h.p.entity.AbstractEntityPersister - Hydrating entity: [com.acme.configuration.model.VeryImportantDate#140]
TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([field_name_] : [TIMESTAMP]) - [2025-03-30 23:00:00.0]
DEBUG o.h.t.d.c.AttributeConverterSqlTypeDescriptorAdapter - Converted value on extraction: 2025-03-30 23:00:00.0 -> 2025-03-30

Hoppácska!

Valamiért, néhány dátum esetében, random időközönként visszateker egy órát a Hibernate, holott nagyon nem kéne neki.

Gondolhatnánk arra, hogy valami timezone problémája van, de az nem magyarázza meg, hogy miért nem konzisztensen, hanem csak véletlenszerűen történik ez meg. Ugyanazon a gépen, pár alkalmazás újraindítás után, akár ugyanabban a 10 perces időablakban.

Rákérdeztem a chat-ben, hogy találkozott-e ezzel bármelyik kolléga...? Egyik javasolta, hogy indítsam a JVM-et UTC-vel (-Duser.timezone=UTC). Ugyan, ez lehet, hogy működik - gondoltam -, de még mindig nem válasz arra, hogy miért csak random időközönként jön elő a probléma. Ha ez a baja, akkor konzisztensnek kéne lennie.

--------

Elkezdtem keresgélni, és szembejött velem a következő: https://stackoverflow.com/questions/75645452/hibernate-localdate-conver…

Na, ez már valami, szóval nekiálltam megnézni, hogy a dátumok hova esnek az idővonalon: https://imgur.com/a/EMIhsRp

És igen! Az összes érintett dátum nyári időszámítás alá esik!

--------

Hát akkor nincs más hátra, csak előre, próbáljuk ki a kolléga által javasolt JVM UTC timezone settinget.

És lássátok feleim, az alkalmazás megjavult! 15+ alkalmazás-újraindítás után se romlott el, szóval úgy látszik ez megoldotta a problémát.

--------

De még mindig nem tudtam, hogy miért csak random időközönként tört el...

--------

Viszont időközben péntek délután lett, meló vége, szóval a jó öreg melós szabály szerint, miszerint: Az "ott bassza meg a kurva anyja" kifejezéssel, minden munka befejezettnek tekinthető, ezért elálltam a további kutakodástól.

A probléma mostmár nem áll fenn. Az Intellij run configba beraktam a JVM paramétert és csináltam neki Pull Requestet. Hétfőn végre kezdhetek valami produktívval is foglalkozni, bár, amúgy élveztem ezt a kis nyomozást is.

Aztán nekiálltam megírni ezt a postot, mielőtt elbicegek a pub-ba.

--------

De azt még mindig nem értem, hogy miért nem konzisztensen jött elő a probléma, miért csak véletlenszerűen...

Hozzászólások

Cuki. Nálam már jó ideje az alap felállás ilyenkor: ha fura gond van a dátumokkal -> valami időzónás szarakodás lesz, ha csak néha van gond velük -> valami nyári időszámításos szarakodás lesz. :) Eddig mindig bejött. Nálunk külön nehezíti a helyzetet, hogy kb. ahány API, annyiféle értelmezése és kezelése van a dátumoknak (util.Date, String, LocalDate, sql.Date, meg ki tudja, még mi).

Lazán kapcsolódó facepalm, amikor pár évvel ezelőtt Nagy Multi Cég Hazai Leánya ügyfélnek sikerült a közjegyzővel(!) együtt olyan "nyerő időpontot" random kisorsolni, ami pont az óraátállítás által hozzáadott egy órába esett bele (02:XX-re esett, amikor 03:00-ról 02:00-ra tekerünk). :D Persze, valahogy ez egyik okosnak sem esett le...rajtam kívül, aztán amikor rákérdeztem, hogy akkor most a téli szerinti vagy a nyári szerinti 02:XX-re gondolt a költő, akkor még nekem kellett hosszasan elmagyaráznom, hogy ezt mégis hogy értem. :)

Hiába, no, szokták mondani, hogy "There are only two hard things in Computer Science: cache invalidation, naming things and off-by-one errors", hát szerintem a "handling time properly"-t is ide lehet venni. ;)

Ahányszor időt akarok adatbázisba tenni mindig elcsábulok, hogy legyen csak egy 64 bites milliszekundum az epoch óta és kész. Emberi nyelvre alakítás a UI feladata a lehető legszűkebb ideig, például csak JavaScriptben, a szerveren minden csak egy szám. (Apropó, arra van már JS API, hogy a böngésző dátumbeállítását lekérdezzük?)

Legutóbb le lettem szavazva mondván, hogy mennyire jó, hogy ha az adatbázisban is időpont jellegű a mező az adatbázisból látszik, hogy mi az érték, nem kell konvertálni. Hát ezért az előnyért én nem mondanék le az egész számok egyszerűségéről, de sajnos nem voltam döntnök. Olyan projekt nincs ahol ne menne el legalább pár nap dátumkonverziós hibákkal.

Ilyenkor örülök, hogy a legutóbbi projekteket, ahol adatbázis van pure SQL-lel kezdtem el. Annak is megvan a maga baja, de legalább pár réteggel kevesebb van. Nyilván azért is tehettem meg, mert kicsi az egész.

Azt, hogy csak néha hibázik hogy kell érteni? Hogy ugyanarra a dátumra néha jó, néha nem? Mert akkor arra gyanakodnék, hogy esetleg egy egy szálra tervezett osztályt több szálról használtok. Például a SimpleDateFormat ilyen, ha jól emlékszem. Minden szálhoz kell egy sajátot csinálni. Oké, itt nem stringgé alakítás van, csak a példa kedvéért mondom. (De lehet, hogy pl az adatbázis valamelyik rétegében stringként jön vissza a dátum és az ojjektummá alakításban rosszul van egy többszálúságot nem támogató helper használva. Az is lehet, hogy a DST csak növeli a hibázás valószínűségét, de a hiba lehetősége enélkül is benne marad a kódban. Sok sikert ahhoz, hogy megtaláld :-) )

A defenzív programozás egyébként némileg védett volna. Ha a feltételezést, hogy nincs hétütközés a dátumban újra ellenőrizte volna a kód, minden hozzáadásnál csekkolta volna, hogy benne van-e már, akkor egyértelműen az első előforduláskor lett volna hibaüzenet, és sokkal kisebb erőfeszítés lett volna debuggolni. Erre a technikára mindenki rácsodálkozik egyszer, hogy valóban mennyire hasznos.

Szerkesztve: 2024. 06. 30., v – 07:52

Azt mondanám, hogy az adatbázis DATE vagy DATETIME mezőjéhez Java oldalon LocalDate vagy  LocalDateTime illene legjobban, kár hogy  ezek csak utólag kerültek be a jdbc-be, és még nem 100%-os a supportjuk.

Ha ez nem megy, akkor lehet a java.sql.Date meg java.sql.Timestamp, de akkor meg érdemes UTC-re lőni, különben a téli/nyári idő bekavar. (Pl. 1956-06-03 00:00:00 nem volt, előző nap 23:59:59 után 01:00:00 következett.)

Szerk: és a char[8] és char[14] is jó lehet.

Itt az első válasz releváns: https://stackoverflow.com/questions/32437550/whats-the-difference-betwe…