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.

September 4, 2017 / by Zsolt Soczó

IIS lassulás probléma – help needed

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

  • Peter September 5, 2017

    É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.

  • Rici September 5, 2017

    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.

  • Soczó Zsolt September 5, 2017

    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.

  • Soczó Zsolt September 5, 2017

    Peter: Dynatrace fut, a szerint a WebClient mélyén a windows api recv-jére vár a hívó webapp.

  • Rici September 6, 2017

    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.

  • Peter September 15, 2017

    Sikerült kideríteni valami izgalmasat?

  • Robert September 19, 2017

    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.

  • Soczó Zsolt September 22, 2017

    Rici, ez jó ötlet, köszönöm, ha lesz rá mód, összevetem.

  • Soczó Zsolt September 27, 2017

    Robert: ez bizarr, de elvileg dedikált magon futnak.

  • Soczó Zsolt November 14, 2017

    Valószínűleg megvan a megoldás. Ha a szerverfarm minden gépén implementálva lesz, és stabil, akkor leírom.