Failover bazy i zwiecha wątku na 2-3h

Baza: SQL Server 2016
Zależności:
org.eclipse.persistence.core: 2.7.3 oraz org.eclipse.persistence.javax.persistence: 2.2.1

Gdy robimy failover bazy to sporadycznie się zdarza tak że wątek który zapisuje zawisa na kilka godzin ale nie wszystkie niektóre rzucą wyjątkiem o braku bazy i potem działają prawidłowo.
W JMC w stacktrace widać że jest to na połączeniu a czasami na innej operacji.
Zrzut z JMC:

do connection stringa dodajemy: queryTimeout=60;cancelQueryTimeout=60;connectTimeout=60

w persistence.xml mamy:

<property name="javax.persistence.query.timeout" value="60000" />
			<property name="eclipselink.jdbc.timeout" value="60000" />
			<property name="eclipselink.jdbc.connections.wait-timeout" value="60000" />
			<property name="eclipselink.jdbc.connection_pool.default.wait" value="60000" />
			<property name="javax.persistence.jdbc.timeout" value="60000" />

i nic to nie daje... Wątek też nie reaguje na interrupta

Przypuszczam że timeouty nie biorą pod uwagę sytuacji że coś się rypnie w trakcie czytania odpowiedzi na przykład. Masz timeout na pobranie połączenia z puli i na wysłanie query, ale jak dostaniesz ACK i jesteś w trakcie czytania odpowiedzi, to będzie czekać do końca świata. Możesz to query robić w jakimś CompletableFuture z timeoutem.

Shalom napisał(a):

Przypuszczam że timeouty nie biorą pod uwagę sytuacji że coś się rypnie w trakcie czytania odpowiedzi na przykład. Masz timeout na pobranie połączenia z puli i na wysłanie query, ale jak dostaniesz ACK i jesteś w trakcie czytania odpowiedzi, to będzie czekać do końca świata. Możesz to query robić w jakimś CompletableFuture z timeoutem.

CompletableFuture - może być bardzo dobrym pomysłem w tej sytuacji. Zastanawia mnie tylko czy cancel lub timeout ustawiony na CompletableFuture ubije to zapytanie czy będzie ono sobie wisiało w pamięci aż się samo odblokuje(lub nie odblokuje) ale plus taki ze główny watek będzie leciał z kolejnymi zapytaniami. Chodzi mi czy nie będzie w tym przypadku szansy na jakieś zapchanie pamięci wiszącymi zadaniami (w ekstremalnym przypadku).

@darksead to już kwestia interfejsu z bazą. CompletableFuture zabije wątek, ale czy gdzieś pod spodem konektor do bazy coś posprząta czy nie, to już cięzko stwierdzić.

Hmm:
https://www.eclipse.org/eclipselink/documentation/2.4/jpa/extensions/q_jdbc_timeout.htm

Use eclipselink.jdbc.timeout to specify number of seconds EclipseLink will wait (time out) for a query result, before throwing a DatabaseExcpetion.

60000 sekund które macie ustawione to ponad 16 godzin :D

damianem napisał(a):

Hmm:

https://www.eclipse.org/eclipselink/documentation/2.4/jpa/extensions/q_jdbc_timeout.htm

Use eclipselink.jdbc.timeout to specify number of seconds EclipseLink will wait (time out) for a query result, before throwing a DatabaseExcpetion.

60000 sekund które macie ustawione to ponad 16 godzin :D

Dobre spostrzeżenie :) dziwne że cała reszta w milisekundach... W poniedziałek poleci próba jeszcze z inna wartością a potem będziemy dalej myśleć czy wrzucić w CompletableFuture jak nie pomoże.

Zmiana czasu eclipselink.jdbc.timeout - nie pomogła.
Co do CompleteableFeature też nie, bo po wywalnieu timeoutu wątek leci dalej i proguje znowu pobrać nowego EntityManagera i wykonać zapis lub update ale ponownie zawisa ale już w innym miejscu.
Wygląda to tak jakby lock na obiekcie w JPA?
W zrzucie wątków widać że ten pierwszy FokJoin wisi w pamięci na sockecie i obstawiam że to on powoduje lock na JPA. O tyle to dziwne ze po wywaleniu timeout robię close na EntityManagerze i z facory tworze nowy.

Nowoutworzony wisi z takim stackiem:

Stack Trace
ForkJoinPool.commonPool-worker-0 [2916] (WAITING)
   java.lang.Object.wait line: not available [native method]
   java.lang.Object.wait line: not available 
   org.eclipse.persistence.internal.helper.ConcurrencyManager.acquire line: 87 
   org.eclipse.persistence.internal.identitymaps.CacheKey.acquire line: 134 
   org.eclipse.persistence.internal.identitymaps.AbstractIdentityMap.acquireLock line: 110 
   org.eclipse.persistence.internal.identitymaps.IdentityMapManager.acquireLock line: 184 
   org.eclipse.persistence.internal.sessions.IdentityMapAccessor.acquireLock line: 101 
   org.eclipse.persistence.internal.sessions.IdentityMapAccessor.acquireLock line: 92 
   org.eclipse.persistence.internal.sessions.AbstractSession.retrieveCacheKey line: 5361 
   org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildObject line: 975 
   org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildWorkingCopyCloneNormally line: 909 
   org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildObjectInUnitOfWork line: 862 
   org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildObject line: 745 
   org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildObject line: 699 
   org.eclipse.persistence.queries.ObjectLevelReadQuery.buildObject line: 853 
   org.eclipse.persistence.queries.ReadObjectQuery.registerResultInUnitOfWork line: 901 
   org.eclipse.persistence.queries.ReadObjectQuery.executeObjectLevelReadQuery line: 568 
   org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery line: 1224 
   org.eclipse.persistence.queries.DatabaseQuery.execute line: 914 
   org.eclipse.persistence.queries.ObjectLevelReadQuery.execute line: 1183 
   org.eclipse.persistence.queries.ReadObjectQuery.execute line: 447 
   org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork line: 1271 
   org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery line: 2981 
   org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery line: 1895 
   org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery line: 1877 
   org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery line: 1827 
   org.eclipse.persistence.internal.sessions.AbstractSession.readObject line: 3821 
   org.eclipse.persistence.internal.sessions.MergeManager.registerObjectForMergeCloneIntoWorkingCopy line: 1108 
   org.eclipse.persistence.internal.sessions.MergeManager.mergeChangesOfCloneIntoWorkingCopy line: 575 
   org.eclipse.persistence.internal.sessions.MergeManager.mergeChanges line: 324 
   org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.mergeCloneWithReferences line: 3614 
   org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.mergeCloneWithReferences line: 389 
   org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.mergeCloneWithReferences line: 3574 
   org.eclipse.persistence.internal.jpa.EntityManagerImpl.mergeInternal line: 643 
   org.eclipse.persistence.internal.jpa.EntityManagerImpl.merge line: 620 
   ****.EntityManagerWrapper.merge line: 47 
   ****.executeUpdate line: 316 
   ****
   java.util.concurrent.CompletableFuture$AsyncSupply.run line: not available 
   java.util.concurrent.CompletableFuture$AsyncSupply.exec line: not available 
   java.util.concurrent.ForkJoinTask.doExec line: not available 
   java.util.concurrent.ForkJoinPool$WorkQueue.runTask line: not available 
   java.util.concurrent.ForkJoinPool.runWorker line: not available 
   java.util.concurrent.ForkJoinWorkerThread.run line: not available 

Wyglada jakby wisiało na locku na sesji JPA. Prawdopodobnie próbujesz coś modyfikować z wielu wątków, a kontekst/sesja jest thread-local. Nie ma to związku z baza danych, problem na poziomie aplikacyjnym. Przydałoby się więcej kodu zobaczyć, robisz coś mocno niestandardowego.

Poza tym robienie IO na ForkJoinPool.commonPool jest niezalecane. Może OP wali po DB ze stream.parallel() ?

Trudno powiedzieć. Dość łatwo można sobie zrobić blokadę nawet na jednym wątku.

1. Jak piszą wyżej - zobacz jak wywalić tego forkJoin Poola - skąd się bierze? Robienie operacji DB z fork join to średni pomysł
2. zrzuć wszystkie wątki (jstack ) wtedy zwykle więcej widać
3. zobacz na bazie danych na czym wisi (jakiś update? )

@0xmarcin: z tego co wiem CompletableFuture używa by default ForkJoinPool.commonPool więc niekoniecznie jest to stream.parallel :P

Na razie robie testy czy zadziala.

Tak uzywam domyslnego CompleteableFuture na probe i on uzywa forkjoin

@jarekr000000: Co do wiszenia to ten pierwszy wisi na sokecie po failoverze bazy a kolejne na locku tym co ostatnio wrzucilem, pewnie przez tego pierwszego.

EntityManager jest threadlocal ale podaje do zadania w CompleteableFeature referencje EM z glownego watku i jak na get dostane wykatek zamykam EM i tworze nowy

To jest dość stare ale jednak: https://www.eclipse.org/lists/eclipselink-users/msg01977.html

Ja nigdy nie pracowałem z Eclipse Link a tu widać problem którego rozwiązanie znajduje się najprawdopodobniej w oficjalnej dokumentacji.

Ja jestem przyzwyczajony do tego że EntityManager związany z transakcją bazodanową jest używany tylko przez jeden wątek, lub w przypadku async przez wiele wątków ale na wyłączność (czyli nigdy przez 2 wątki na raz nawet jeżeli jest to odczyt).

Jak się używa Springa w webapp'ie to zazwyczaj jest to ukrywane pod proxy i nikt tego nie zauważa. No tutaj ty się bawisz w "ręcznie" w async, trzeba by sprawdzić w docs czy to jest oficjalnie wspierany w Eclipse Link.

Robisz jakieś dziwne rzeczy i trzymasz wszystkich w napięciu :) pokaż kod. Ja się już zgubiłem, czy ten Future to jest próba na obejście problemu czy jego główny powód

Kodu niestety nie moge wrzucić :P Ale pierwotna wersja kodu nie używała CompleteableFuture, tylko leciało to w jednym wątku odpowiedzialnym za zapis/update. Użycie CompleteableFuture było pomysłem Shalom chciałem je po prostu przetestować jako obejście problemu ale jak widać nie działa jak powinno. :)

Ok, a próbowaliście zobaczyć jak to wyglada z punktu widzenia bazy danych? Mogą być deadlocki transakcji na samej bazie, wtedy aplikacja czeka np. na tablocku, żeby przeczytać dane.

Niektórzy nie czytają chyba wątku od początku :P CompletableFuture to był tylko pomysł na ubicie tych wiszących operacji -> ustawić timeout i jak przeleci to zabijać wątek. Nie rozwiązuje to problemu OPa, ale przynajmniej potencjalnie miało szanse na powstrzymanie godzinnych deadlocków.
Ja osobiście właczyłbym logowanie SQLa z JPA i patrzył co leci do bazy plus monitorował na poziomie bazy co się dzieje.

Zmiana czasu eclipselink.jdbc.timeout - nie pomogła.

To znaczy że wątek dalej wisi w tym samym miejscu? No to albo coś jest dalej źle ustawione albo Eclipselink ma dość krytycznego buga (bardziej wierzę w to pierwsze).
Dla mnie rozwiązanie to poprawne ustawienie timeoutu i dodanie validation query do data source żeby takie wiszące połączenia nie były ponownie używane i żeby były usuwanie z puli.

Na poziomie TCP socket timeout przy czytaniu (maksymalny czas który może minąć między dwoma kolejnymi pakietami) oraz próba wysłania czegoś to jedyna opcja żeby stwierdzić że druga strona (baza) umarła. Bo skoro klient nie dostał FIN ani RST to skąd ma wiedzieć? :)

Któreś z propertiesów Eclipselink / DataSource powinno się mapować na socket timeout.

Gdy robimy failover bazy to

Co się kryje za tym hasłem? Co dokładnie robicie?

Zrobiłem próbę z nadpisaniem klasy SocketFactory dla jdbc i ustawiam na tworzonych Socketach setSoTimeout(60000); przed zwróceniem, ale to niestety też nie pomogło.
Dostrzegłem w logach jeszcze coś takiego:

Nov 03, 2020 1:02:24 PM com.microsoft.sqlserver.jdbc.TDSCommand log
WARNING: TDSCommand@35ed26e6 (SQLServerPreparedStatement:177177 executeXXX): Command could not be timed out. Reason: Socket closed

@damianem tak, watek ciagle zawiesza się na:

   java.net.SocketInputStream.socketRead0 line: not available [native method]

Po stronie bazy nie widać żadnych wiszących zapytań/transakcji

Kolejna rzecz którą można sprawdzić to cache DNS, może być tak że przy zmianie node nadal jest próba łączenia się ze starym.
Najlepiej podbić też JDBC driver do najnowszej wersji, tutaj jakiś bug dość świeżo zafixowany który brzmi podobnie: https://github.com/microsoft/mssql-jdbc/issues/1325

@darksead: do czego łączy się aplikacja? Do availability group / failover cluster / do noda?
Sterownik JDBC 4.0 MSu ma dodatkowe właściwości:

• multiSubnetFailover
• applicationIntent

Ustawiacie? Czy może wiecie, że nie są potrzebne w Waszym przypadku?

JDBC został zaktualizowany wczoraj rano do wersji 8.4.1 i niestety dalej to samo.

JPA tez próbowaliśmy zaktualizować do:

<dependency>
			<groupId>org.eclipse.persistence</groupId>
			<artifactId>org.eclipse.persistence.jpa</artifactId>
			<version>2.7.7</version>
		</dependency>

I po podmiance jpa sypie dziwne błędy na odpytaniu procedór, których w ogóle nie ma na 2.7.3 :

Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The index 2 is out of range.

Pytanie czy te wieszanie na socketach może być spowodowane wirtualizowanym środowiskiem / zla konfiguracja sieci? bo są to maszyny wirtualne na serwerach obecnie.

@yarel do do głownego węzła czyli Avability group. Co do tych ustawień to po stronie aplikacji mamy uzycie multiSubnetFailover=true.

Wszystko wskazuje że jest to problem środowiska. Sprawdziliśmy na innym i problemu na razie nie udało się zreprodukować.
Niestety nie mam już linku, ale na stronie Oracla też było w zeszłym roku zgłoszenie dla tego problemu i też było wskazanie że powodem było środowisko.

Przy okazji udało się też znaleźć w razie potrzeby niezbyt ładne ale działające obejście problemu jeśli by się okazało że na produkcji też by to wystąpiło a było ciężko dojść co w konfiguracji piszczy. Może się też komuś przyda:

1. Jest osobny wątek który monitoruje życie pozostałych wątków aplikacji
2. Jak wątek monitorujący wykryje że wątek nie odpowiada to sięgamy do jego referencji do EntityManagera (wątek musi trzymać i udostępniać referencje do EM dla którego obecnie rozpoczęta została transakcja)
3. Sprawdzamy czy transakcja jest otwarta, jeśli tak to pobieramy z transakcji obiekt Connection i robimy na nim close()
4. Wątek dostaje wyjątek o zamknięciu socketa i tym samym zostaje odblokowany.