Kivételesen nem megoldást írok le, hanem kérdést teszek fel.
Egyik ügyfelemnél vagy egy eset, amit egyelőre nem sikerült visszafejteni. Adott 3 IIS publikus web láb NLBS-sel összenyalábolva, és 3 belső IIS alatt futó WS szintén NLBS mögött, ezeket hívják a külső webappok. A Windowsok VmWare alatt vannak virtualizálva.
A hiba az, hogy random időpontban belassulnak a webszerverek webszervizek irányába mutató hívásai. Normál esetben egy gyors ws metódus hívása 2-5ms, amikor beáll ez az állapotváltás a webszerver worker process belsejében, akkor felmegy kb. 200 ms-re.
Azért írok állapotváltást, mert nem azért lassulnak be a dolgok, mert nap közben nagyobb a terhelés, hanem egyszer csak “elborul” a webapp, és belassul. Dynatrace alapján a ws hívások mélyén a recv windows hívás válaszol lassan. Ilyenkor a ws iis logjában is lassú a hívás, vélhetően mert a webapp mint kliens lassan viszi el az adatot.
Hamarosan lesz DotTrace lenyomat és FREB log is, illetve System.NET trace is (csak ez nagyon sok adatot termel).
IIS App reset megoldja a problémát egy ideig. Ha egy app beteg, akkor egy console appból ugyanaz a ws hívás ugyanezen a gépről a wsek felé gyors, tehát nem valószínű, hogy a wsek lassulnak be.
Nehézkes megfogni az estet, mert pl. egy config módosítás a trace-ek kedvéért azonnal appol resetet csinál, így elillan a hiba, aztán lehet megint egy napot várni rá.
A .NET perf counterek nem mutatnak kiugró értékeket, minden normálisnak tűnik. A web processben kb. 500 szál fut 1-3 kérés/sec esetén, ez mondjuk kicsit soknak tűnik, de a procmon nem mutatta meg a managed stacket (debug symbolokkal se), majd csak dottrace-ből látszik, mit csinálnak. A procik 10%-ig vannak kiterhelve. A diszk terhelés minimális, paging nincs, van 0.5G szabad memória, más proceszek nem eszik el az erőforrásokat. A resource monitorban a wsek irányába futó kérések jelentős része 200ms körüli latency-t mutat, ez egybevág más megfigyelésekkel.
Látott már ilyet valaki? Mit lehetne még mérni, amire nem gondoltam?
Could you hire me? Contact me if you like what I’ve done in this article and think I can create value for your company with my skills.
LEAVE A COMMENT
11 COMMENTS
És amikor beáll a lassulás, akkor az képes magától helyre jönni, vagy onnantól az az állapot van?
Az ugrás szerintem túl kicsi ahhoz, hogy infrastrukturális baja legyen, de azért kíváncsi lennék a VM-ek specifikációjára [0.5 GiB memóriát én keveslem, mint szabad], illetve a w3wp-k memóriafoglalására. Ami még érdekes lehet, hogy nem-e a load balancer-ek játszanak valamit a socket-ekkel, illetve kérdés még, hogy egyáltalán a service-eket min keresztül lehet elérni, HTTP(1.0, 1.1), más?
Ha a web service log-jában is látszik a lassú hívás, akkor gondolom, nem szabad kapcsolatra vagy hasonlóra vár a web app, nem tudom, visszairányban ki lehet-e ilyenkor még éheztetni az app-ot vagy sem hasonló módon.
A 200ms plusz egyébként nekem nagyon annak tűnik, mikor a service hívásban a request sok időt tölt el az “AcquireRequestState” fázisban, olyan, mintha a shared session-re várna, hogy tudja lock-olni. Ilyet látok minden nap “nálunk”, még nem sikerült kijavíttatni…
Én mindenképpen ilyen shared state-eket keresnék.
Amit még ki lehetne próbálni, az egy New Relic vagy hasonló megoldás, ami meg tudná mutatni összefüggésében is a dolgokat.
Csak app recycling segit.
Szerintem nézd meg, hogy nincs-e valami a Nagle algorithm-mel (még TCP NoDelay néven is ismert, ez az, amikor ki van kapcsolva a Nagle algorithm).
https://msdn.microsoft.com/hu-hu/library/system.net.sockets.socket.nodelay(v=vs.85).aspx
Azért jutott eszembe, mert az pont 200 msec defaultból.
Rici: igen, Nagle képbe került, de nem kapcsoltuk ki, mivel azt valószínűleg nem oldaná meg az IIS reset. Mindenesetre egy mérést megér.
Peter: Dynatrace fut, a szerint a WebClient mélyén a windows api recv-jére vár a hívó webapp.
Megnézném egy Wireshark-kal vagy hasonló network capture programmal a pontos időzítést, pontosabban összevetném a Dynatrace eredménnyel. A kérdés, hogy a recv hívás kezdete és befejezése hogyan viszonyul a hálózati csomag beérkezéséhez.
Ha a recv kezdete környékén már ott van a csomag, akkor a fogadó gépen és a kliens processzben kell tovább nézegetni, pl. nem lehetséges-e, hogy a sok szál miatt van valami gond.
Ha csak a recv hívás befejeződése környékén érkezik meg a csomag, akkor úgymond jogosan várakozik a recv hívás. Ez utóbbi esetben az egy elég érdekes kérdés, hogyan tudja rávenni a szervert egy adott kliens processz, hogy csak és kizárólag neki késleltetve küldje a válaszokat.
Még egy tipp, hogy esetleg a hálózati kártya driverében van valami bug. Főleg, ha TCP offload be van kapcsolva, amikor is a TCP logika egy részét a hálózati kártya és a driver implementálja.
Sikerült kideríteni valami izgalmasat?
A virtualizált környezetben dedikált cpu magokon fut a windows?
Egy ügyfelünknél többszáz millis várakozásokat okozott a webcontainer
szálaknak, hogy az oprendszer elemi műveleteire vártak. Minél több virtuális magot
rendeltek a guesthez annál gyakrabban fordult elő a probléma.
Egyetlen dedikált mag megoldotta a problémájukat, az alkalmazás végig
hibátlan volt.
Rici, ez jó ötlet, köszönöm, ha lesz rá mód, összevetem.
Robert: ez bizarr, de elvileg dedikált magon futnak.
Valószínűleg megvan a megoldás. Ha a szerverfarm minden gépén implementálva lesz, és stabil, akkor leírom.