This is an old revision of the document!
Folosirea memoriei de catre un proces e un lucru dinamic. Astfel, la un moment dat e posibil sa fie un spike de alocare, dupa care sa revina la normal. Daca ne intereseaza un singur process cata memorie a avut alocata, probabil ca Task Manager e sufficient ca sa ne raspunda la intrebare, uitandu-ne in zona details la Peak Working Set.
Putem observa din imaginea de mai sus ca Peak Working Set poate fi uneori semnificativ mai mare decat Working Set.
Ce facem cand stim ca pe system avem probleme in anumite conditii reproductibile, stim ca ajungem sa nu mai existe memorie pe system, dar nu stim cine genereaza aceste probleme? Pentru a afla cine produce problema putem sa pornim Windows Performance Recorder configurat ca in poza de mai jos:
In parallel am pornit un program care la fiecare 100 milisecunde aloca 1 MB de memorie timp de ceva vreme, dupa care se inchide brusc. O data terminat de creat captura, dam Save, deschidem in Windows Performance Analyzer si obtinem:
Dam Add all Memory graphs to Analysis View, scrolam pana la graficul Virtual Memory Snapshot unde vedem graficul folosirii memoriei de toate procesele:
Astfel vedem graficul cresterii foarte abrupte a folosirii memoriei procesului nostru, de unde tragem concluzia ca el ar putea fi generatorul de probleme, avand in vedere ca restul sunt destul de stabile.
Ok, am identificat procesul care ne face probleme, ce facem mai departe. Daca nu e scris de noi, verificam cine il lanseaza, vedem daca avem nevoie de el si daca nu, il dezactivam. Daca avem nevoie de el, verificam daca exista vreun update al lui care sa fixeze problema. Daca nu gasim nici un update care sa fixeze problema, incercam sa raportam problema producatorului si sa speram ca o sa o fixeze.
Daca este procesul nostru, sa vedem ce putem face. Pentru identificarea memory leakurilor exista un tool foarte puternic care poate fi descarcat de pe:
Se instaleaza si prin includerea fisierului vld.h in crearea programelor se vor suprascrie functiile malloc, free, new, delete, astfel fiecare alocare si dezalocare va fi traceuita si daca o alocare nu este urmata de o dezalocare ni se va da la sfarsitul programului un log cu toate leakurile detectate.
Se poate observa includerea #include <vld.h> si dupa rularea programului in partea de jos se poate observa stiva de unde s-a facut alocarea fara dezalocare. Totusi, daca nu este un leak, ci in final la sfarsitul programului totul se dezaloca frumos, cum putem identifica care parte a programului a generat spikeul.
Introducem un nou tool de la sysinternals
https://technet.microsoft.com/en-us/sysinternals/vmmap.aspx
Acesta e un tool foarte puternic de la Sysinternals care ne ajuta sa vedem alocarile si folosirea memoriei de catre un proces. Sa rulam primul program care genera multe alocari la fiecare 100 milisecunde cu ajutorul acestui tool:
Inainte de a porni toolul ne ducem in Options→Configure Symbols si punem acolo calea catre pdb-urile specifice programului nostru si respective spre serverul de simboluri Microsoft, precum si calea catre sursele programului nostru.
Se porneste toolul, selectam tabul Launch and trace a new process, selectam procesul care ne intereseaza, spunem care sa fie directorul de unde sa ruleze si ii dam drumul sa ruleze. O data pornit toolul o sa vedem ceva de genul:
Trebuie sa dam dublu click in zona de sus pe Heap, sa dam din cand in cand F5(refresh) pentru a vedea proaspetele alocari si in partea de jos o sa vedem alocarile, daca dam click pe unele din ele si apasam butonul de jos Heap Allocations o sa obtinem si stiva unde s-a produs alocarea, dupa care daca apasam butonul source vedem efectiv si codul care a produs alocarea.
Si in cazul CPU Usage avem oarecum probleme similare cu cele pentru memory usage. Daca vrem sa aflam consumul din acest moment de CPU al unui process, ne este de ajuns Task Manager:
Ok, apare aceeasi intrebare, daca avem un spike de CPU, care dispare dupa aceea, cum il putem identifica – cu Task Manager ar insemna sa stam continuu sa ne uitam sa vedem ce se intampla. Din nou vom folosi Windows Performance Recorder, setarile le vom face ca mai jos:
Dupa ce dam start, mergem in zona de resurse descarcate pentru acest laborator si pornim exexcutabilul CPUUsage.exe – executabil care genereaza mult consum de CPU.
Dam save si deschidem captura:
Dupa cum se poate observa si in imagine – ne ducem pe zona Computation, dam click dreapta si apasam optiunea Add all Computation graphs to Analysis View:
Din grafice se observa impactul de vreo 12% al programului nostru. Ok, am identificat problema, am vazut cine genera consumul de CPU – acum apare intrebarea cum debugam acest lucru? La fel ca si la memory, daca nu e un process scris de noi, vedem daca ne e util, daca nu ne asiguram ca nu mai ruleaza. Daca ne e util incercam sa gasim un update pentru el in speranta ca nu se mai reproduce problema. Daca nu gasim un astfel de update raportam problem ape forumurile producatorului in speranta ca se va fixa. Dar cum la evaluarea performantelor ne intereseaza sa analizam procesele scrise de noi, o sa presupunem ca acest process, cum se si intampla de altfel, e scris de noi, si e impotant sa gasim de unde a aparut problema. Din pacate, spre deosebire de cazurile discutate mai sus, lucrurile nu mai sunt la fel de simple, neexistand un tool care sa ne dea stiva unde se genereaza problema, de data aceasta va trebui sa ne cream noi acest tool.
Va rog sa deschideti EvenimenteProcMon. Scopul programului e de a ne integra mesajele noastre cu ProcessMonitor, ca sa le putem vedea pe masura ce se desfasoara procesul. O sa explic un pic programul, desi nu e musai necesar s ail intelegeti. Ca si QA puteti cere dezvoltatorului sa integreze el cu process monitor pentru a va ptuea permite sa investigate. Dar, consider totusi ca, ca si QA e totusi nececsar sa puteti intelege orice fel de cod – nu perfect, dar macar sa aveti idee cam ce se intampla, de aceea sper sa va fie cat mai clar codul explicat mai jos:
Deci, am creat o clasa ProcessMonitor, care are 5 functii:
OpenProcMon deschide un handle la interfata de mesaje a ProcessMonitor
CloseProcMon inchide acel handle
ProcMonLog scrie mesajul pasat ca parametru in interfata ProcessMonitor
MyProcMon e constructorul clasei, el va fi apelat cand am declarant un obiect ded tip MyProcMon
~MyProcMon e destructorul clasei, el va fi apelat cand se va distruge obiectul de tip MyProcMon.
Mai jos in cod vedeti ca am declarant global:
MyProcMon procMon; Aceasta inseamna ca la pornirea procesului, inainte de executia functiei main cand se initializeaza variabilele globale, va fi construit obiectul clasei noastre si implicit deschiderea handelului peste interfata de mesaje din ProcessMonitor. Inchiderea handeului facandu-se cand se distruge obiectul, adica dupa executia programului. Pe langa clasa de mai sus, am mai declarat o clasa – ProcMonLogFunc, al carui scop este sa afiseze cat mai simplu cand intra intr-o functie si cand iese. Pentru aceasta am definit macroul: #define DBGTRACE_FN_() ProcMonLogFunc my_log(FUNCTIONW__) care declara un obiect de tip ProcMonLogFunc caruia ii da ca parametru numele functiei curente. Astfel, pus macroul la inceputul unei functii el va afisa la inceputul functiei numele functiei si la iesire, cand se distruge obiectul declarant, va afisa faptul ca iese din functie.
Ok, inarmati cu toate acestea sa pornim ProcessMonitor, sa schimbam filtru in care sa punem ProcessName contains EvenimenteProcMon. Selectam butonul de Profiling ca in figura de mai jos:
Rulam programul si obtinem o captura de ProcessMonitor de genul:
Astfel daca va uitati o sa vedeti mesaje de genul Output: =⇒ Func1 si Output: ⇐=Func1, iar timpii intre care se desfasoara aceste doua evenimente pot fi gasiti in stanga in coloana Time of Day: 4:42:07.1848883, respective 4:42:07.1848955 adica o diferenta de 72 , timpii dupa virgula sunt exprimati in sute de nanosecunde, adica func1 a durat 7.2 microsecunde.
Ok, sa facem calculul de mana pentru fiecare functie, e evident inefficient, asa ca salvam outputul in format csv (File→Save si din optiunile de save alegem Comma-Separated Values) si obtinem in fisierul salvat informatia de genul acesta:
"4:42:07.1846936 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: ==>main" "4:42:07.1848812 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: Acesta e logul meu 1" "4:42:07.1848883 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: ==>Func1" "4:42:07.1848955 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: <==Func1" "4:42:07.1848990 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: ==>Func2" "4:42:07.1849038 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: <==Func2" "4:42:07.1849069 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: ==>Func3" "4:42:07.1849105 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: <==Func3" "4:42:07.1849148 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: Acesta e logul meu 2" "4:42:07.1849184 PM","EvenimenteProcMon.exe","6352","Debug Output Profiling","","","Output: <==main"
Daca ne facem un parser intelligent, in python sa zicem ca ar fi mai usor putem identifica timpii de intrare si iesire din functii, facem diferenta si vedem cat a stat in fiecare functie in total, astfel avem si raspunsul unde a pierdut cel mai mult timp programul nostru. Daca vrem sa ne concentram doar pe consumul de CPU, atunci inainte de scrieri pe disk, ar trebui sa avem un mesaj de log inainte si dupa, astfel incat sa scadem operatiile de I/O.
Acum, va propun sa ne intoarcem la CPUUsage, sa il integram cu ProcessMonitor sis a vedem cat a stat in fiecare functie in total.
Si in cazul network monitoring, conteaza foarte mult ce dorim sa vedem. Daca vrem sa vedem traficul pe care il face un process pe retea la un anumit moment dat, ne e de ajuns Task Manager:
In resurse gasiti Winhttp.exe, un programel facut sa downloadeze putty.exe. In imaginea de mai sus puteti observa activitatea acestuia pe retea. Acum urmatoarea problema, daca nu stim care e procesul care creaza activitatea pe retea, atunci ca de obicei folosim Windows Performance Recorder configurat ca mai jos:
Dupa ce salvati inregistrarea si o deschideti o sa vedeti ca Windows Performance Analyzer nu ne ajuta foarte mult, pentru ca nu ne da statistici per process, ci doar statistici totale decat e folosita reteaua. De aceea vom introduce un nou tool Network Monitor – produs tot de Microsoft. Se poate da jos de pe:
https://www.microsoft.com/en-us/download/details.aspx?id=4865
Se instaleaza, se porneste cu Run as administrator, se selecteaza interfata de rete ape care ne asteptam sa fie traficul (iesirea pe cablu, wifi, etc). Iata cum arata o captura facuta cu el:
Ca si in cazul CPU-ului inspectarea a ceea ce se intampla pe retea implica un pic de munca din partea analistului. In cazul de fata lucrurile sunt simple, se expandeaza traficul facut de winhttp.exe si se poate observa ca e un request facut pentru un putty.exe. Daca nu e clar de ce se fac unele requesturi sau de ce dureaza atat de mult, se poate integra aplicatia investigata cu ProcessMonitor si introduse elemente de logging dupa cum am vazut pentru a vedea ce requesturi se fac si cat dureaza. Partea cu cat dureaza requestul si traficul se poate vedea direct din Network Monitor uitandu-ne la timpii pe care i-au avut pachetele.
In final, o sa va mai propun un tool cu ajutorul caruia putem vedea tot traficul schimbat pe o conexiune (http, se poate sip e https atata vreme cat controlam serverul, dar nu e scopul acestui laborator). Toolul se numeste wireshark si poate fi dat jos de aici:
https://www.wireshark.org/download.html
O data ce dati jos instalerul si instalati(puteti da linistit Next, Next, Next in procesul de insalare si sa acceptati setarile default)porniti wireshark.
Selectam interfata pe care vrem sa ascultam- wifi in cazul meu:
Apasam butonul start si pornim si programul winhttp.exe. Dupa ce s-a terminat winhttp.exe, apasam butonul stop:
Si avem captura traficului din perioada cat a rulat winhttp.exe. Observam din codul winhttp.exe ca requestul se face catre www.sociouman-usamvb.ro, ii aflam ip-ul:
In wireshark mergem in zona Filter si adaugam filtru ip.addr == 86.106.30.115. Dupa ce avem traficul filtrate mergem pe requestul facut – Get documents/Elemente_de_istorie_a_Romaniei.pdf, dam click dreapta si apasam Follow TCP Stream:
Punem la Show and save data as – Raw, dam Save As – dam numele my.pdf:
Deschidem cu notepad++ fisierul my.pdf salvat si eliminam headerele ca in imaginea de mai jos:
Dam din nou save, inchidem Notepad++ si dam dubluclick pe pdf-ul proaspat salvat:
Dupa cum puteti vedea am reusit sa obtinem un pdf valid, adica am reusit sa extragem din conversatie datele conversatiei. Acest lucru a fost posibil datorita faptului ca era comunicatie http, altfel pe https atata vreme cat nu controlam serverul ar fi fost mult mai complicat.
In concluzie am vazut cum putem monitoriza ce se intampla pe retea si cum putem vedea efectiv traficul.