todvora / eet-client

Client and library for #EET communication - http://www.etrzby.cz/ , written in Java
MIT License
48 stars 26 forks source link

DNS timeout check #22

Closed rds76 closed 7 years ago

rds76 commented 7 years ago

Myslim, ze to overeni DNS lookupem nefunguje zcela korektne. Provedel jsem nejake real testy v provozu s 5s lookup timeoutem a zaroven kazdou minutu pomoci utilitky dig kotroluji query time na stejnem stroji, kde eetclient bezi. Zatimco vsechny query time jsou do 500ms v prumeru kolem 200ms, eetClient se do 5000ms limitu obcas nevejde.

todvora commented 7 years ago

Díky za test! Ono se toho při tom ověření neděje mnoho. Zato Java sama o sobě provádí ve třídě InetAddress poměrně hodně, včetně synchronizace vláken. Bylo by možné test zopakovat ještě jednou, jen místo dig použít javu napřímo? Třeba jen jednoduchou utilitku typu:

import java.net.InetAddress;
import java.net.UnknownHostException;
import java.util.concurrent.TimeUnit;

public class Application {
    public static void main(String[] args) {
        final String host = args[0];
        final long start = System.nanoTime();
        try {
            InetAddress address = InetAddress.getByName(host);
            final String ip = address.getHostAddress();
            System.out.println(host + " -> " + ip);
        } catch (UnknownHostException e) {
            System.err.println("Failed to lookup " + host);
        } finally {
            final long stop = System.nanoTime();
            System.out.println("Lookup took " + TimeUnit.NANOSECONDS.toMillis(stop - start) + " ms");
        }
    }
}

Zatím bohužel nemám, čeho bych se chytil a co bych mohl upravit.

Díky, Tomáš

rds76 commented 7 years ago

Tim testem jsem chtel naznacit, ze problem neni v lookup hostname potazmo problemu se siti, ale v samotne jave. Kod mohu vyzkouset, nicmene spise podezrivam konkretne tu cast kodu samotheno executoru a jeho vytvareni vlaken obzvlaste pokud to bezi pod JVM celeho kontejneru a kde neni zrejme s jakou prioritou je to vlakno pusteno, sychronizovano ap., ale jak pisete, mozna i samotne trida InetAdress muze lagovat. Tady je primo reseni od Oracle coz je hodne podobne tomu Vasemu. Napada me jeste takove reseni nastavit system prop networkaddress.cache.ttl=-1 viz InetAddress tim by mel stacit prvni uspesny lookup a dale by uz k blokovani DNS nedoslo a vytimeoutovalo by to az v samotne WS. Ale nicmene jsem si vsiml, ze produkcni eet ukazuje na vice IP adres, ktere pravdepodbne vraci podle aktualniho vytizeni.

todvora commented 7 years ago

Produkční endpoint EET je za load-balancerem, dlouhodobé cachování IP by tak byla asi chyba.

Souhlasím, že problém může být v Javě a overheadu, který přidávají vlákna. Pak ale taková aplikace nejspíš běží na hraně zdrojů, nebo ne?

Jak dál? Doplníme nějaké logování, abychom zjistili, jestli to brzdí samotný lookup a třída InetAddress nebo executor a vlákna?

Máte změřeno, za jakou dobu se vykoná celé odeslání a přečtení odpovědi? Je to očekávaných několik sekund nebo znatelně víc?

Díky! Tomáš

rds76 commented 7 years ago

Zde mam nejake vysledky testovani. Nechal jsem soubezne bezet kazdou minutu a testoval query time pomoci dig a Vasi java test aplikace. Ve vetsine pripadu jsou ty casy +- stejne nicmene java app za dobu asi 1.5dne vykazala cca 4 excesy. Ukazka nejhorsich casu dig:

02-22 23:03|598
02-22 15:47|603
02-22 15:45|609
02-21 14:59|671
02-22 16:57|707
02-21 15:53|744
02-22 14:12|807

java:

prod.eet.cz -> 5.145.105.132 Lookup took 748 ms
prod.eet.cz -> 5.145.105.133 Lookup took 750 ms
prod.eet.cz -> 5.145.105.132 Lookup took 802 ms
prod.eet.cz -> 5.145.105.132 Lookup took 3964 ms
prod.eet.cz -> 5.145.105.133 Lookup took 5159 ms
prod.eet.cz -> 5.145.105.133 Lookup took 10377 ms
prod.eet.cz -> 5.145.105.133 Lookup took 10984 ms

Java app startovala vzdy nove JVM, tzn nebezelo to pod zadnym j2ee kontejnerem. Jinak na hrane zdroju kontejner rozhodne nebezi.

todvora commented 7 years ago

Super test, díky! Teď jak z toho ven? Pokud i tahle zcela holá java aplikace vykazuje podezřelé záseky, není z pohledu knihovny nejspíš žádná možnost, jak to řešit.

Zkusím obdobný test zopakovat na mém připojení a systému. Třeba se k něčemu doberu.

Máte nějaký nápad, kde by mohl být problém?

rds76 commented 7 years ago

Bylo by mozne pridat do logovani tech casu EET response, cas behu cele metody submit. Ja ten lookup test mam aktualne deaktivovany a docela by me zajimalo jaky je skutecny cas celeho volani. Popr. to mohu merit sam, ale kdyz to bude na jednom miste v jednom radku bylo by to fajn.

Jinak k tomu problemu, tezko rict jestli ten vysledek neni nahoda a lookup casy takove jsou v dany moment, proto bude lepsi udelat jeste test jak pisete u Vas. Ale osobne si myslim, ze takto laguje samotna java. Jeste jsem udelal testovaci aplikaci pomoci toho prikladu od Oracle, ktery vyrabi executor s vlastnim Thread. Tak zkusim jake budou odezvy.

rds76 commented 7 years ago

Jeste jsem neco objevil http://www.xbill.org/dnsjava/ Obsahuje mimo jine SimpleResolver tridu s moznosti nastaveni timeoutu (throws SocketTimeoutException). Samotny lookup probiha vlastni TCP nebo UDP tridou. Aktualne testuji tu prilozenou java dig aplikaci jake vraci query time, ale casy vypadaji dost realne... Takze zde je mozna reseni.

rds76 commented 7 years ago

Zde jsou vysledky mereni za 3 dny (1min interval) resolveru pomoci dnsjava knihovny, nejhorsi casy:

02-25 11:55|709
02-26 23:53|717
02-27 07:27|748
02-27 07:30|748
02-26 23:49|762
02-24 15:48|798
02-26 23:55|828
02-27 03:53|834
02-26 05:21|1192
02-26 20:46|1196
02-24 14:43|3681

Zda se, ze toto funguje...

todvora commented 7 years ago

To vypadá dobře, ale pokud použiji tuto knihovnu pro ověření timeoutu DNS, stejně nakonec dojde uvnitř CXF na InetAddress a problém tak budeme řešit dvakrát. Nebo jsem něco přehlédl?

rds76 commented 7 years ago

Jde o to, ze se korektne otestuje resolver resp. network, coz byl asi puvodni zamer a eliminuji se chybne timouty java InetAddress class. S tim, ze to nakonec zalaguje asi nic neudelame. Navic co jsem vypozoroval, tak nasledne lookupy samotonou tridou ihned po otestovani tou knihovnou byly defakto okamzite, asi diky loklani dns cache samotheno systemu.

todvora commented 7 years ago

Nerad bych přidával další závislost a raději bych ponechal InetAddress jako default implementaci. Ale chápu, že by bylo vhodné mít možnost použít vlastní DNS resolver, pokud default z nějakého důvodu nevyhovuje.

Můj návrh vypadá takhle: https://github.com/todvora/eet-client/blob/dns-resolver-configurable/src/main/java/cz/tomasdvorak/eet/client/dto/WebserviceConfiguration.java#L51

Dns resolver lze podstrčit v konfiguraci z venku a můžete tak klidně použít implementaci založenou na dnsjava. Kontrolní vlákno a timeout stále zůstávají.

Bylo by to takhle vyhovující?

rds76 commented 7 years ago

Muze byt, ale jak jsem uz psal, ja DNScheck pouzivat nebudu

todvora commented 7 years ago

OK, každopádně díky za input, merguji a zavírám issue.