Page History
...
Indeværende dokument et sammendrag af dokumentet MinLog2-Testvejledning og performance. Performance rapporterne findes som selvstændige under dokumenter.
Læsevejledning
Læseren forventes at have kendskab til National Sundheds-IT's platform NSP, samt generelt kendskab til WildFly applikation server, MariaDB, Kafka og java.
...
Version | Dato | Ansvarlig | Beskrivelse |
1.0 | 10-10-2019 | Openminds | |
| 1.1 | 26-03-2020 | KvalitetsIT | Performance test rapport lookup |
| 1.2 | 27-05-2020 | KvalitetsIT | Performance test rapport registration |
| 1.3 | 14-12-2020 | KvalitetsIT | Performance test rapporter flyttet ud i eget under dokument |
Definitioner og forkortelser
...
Performance
Det følgende beskriver performance test og analyse for
- MinLog2 - Performancetest rapport borger lookup
- MinLog2 - Performancetest rapport medhjælper lookup
- MinLog2 - Performancetest rapport minlog1 lookup
Først beskrives de forskellige typer test data output, og hvordan de anvendes i analysen. Herefter skitseres scope og afvikling af testene samt performance kravene. Og endelig analyseres data for hver enkelt test.
Se iøvrigt krav til performance test og rapport på siden https://www.nspop.dk/display/public/web/Performancekrav
Performance analyse
For alle test gælder følgende:
Udover det fremsatte performance krav på svartid, er der en række andre punkter som bør analyseres for at vurdere servicens sundhed.
Følgende punkter bliver derfor undersøgt:
- Svartid per kald
- Antal kald per sekund
- Cpu status
- io på netværk
- Hukommelses forbrug
- Garbage collection
Der er ikke målinger på database serveren (MariaDB) eller Kafka serveren.
Undersøgelserne foregår vha. de forskellige log filer, som er genereret under performance testen. De følgende afsnit gennemgår de vigtigste tal fra disse filer:
- JMeter log data belyser
- Faktisk antal test iteration kørt
- Throughput
- (Ex: docker01.bo.stage.nsp.netic.dk-perflogs/minlog_listlogstatements_borger_stress01.nsp-test.netic.dk_master_20200309_110341.tar.gz.log)
- Access log (applikations server information) belyser
- Antal kald per sekund
- Svartid per kald
- De nedenstående grafer som er dannet fra denne log er lavet i splunk af Arosii.
- (Denne log er ikke inkluderet da den indeholder personfølsomme data)
- vmstat log (system information) belyser
- cpu status
- skrivning til disk
- Logning sker hver 10. sekund
- (Ex: docker01.bo.stage.nsp.netic.dk/docker01.bo.stage.nsp.netic.dk-vmstat-20200309101455.log)
- jstat log (JVM information) belyser
- Hukommelse (heap) forbrug
- Garbage collection
- Der er tidsstempel per log linie
- (Ex: docker01.bo.stage.nsp.netic.dk/docker01.bo.stage.nsp.netic.dk-docker-jstat-gc-stage_bo_comp_minlog_backend_lookup.log)
- docker stats log (container information) belyser
- Hukommelse
- io på netværk
- Der er ikke noget fast logningsinterval.
- (Ex: docker01.bo.stage.nsp.netic.dk/docker01.bo.stage.nsp.netic.dk-docker-jstat-gc-stage_bo_comp_minlog_backend_lookup.log)
Hver kørsel/iteration (øgning af belastning) har en start og slut tid. Filerne access.log og jstat.log indeholder tidstempler. Dette muliggør at de kan mappes til en given iteration. Filen vmstat har ikke tidstempel. Men da den er startet samtidig med jstat loggen og logintervallet er kendt på 10 sekunder, kan iterationernes placering i data beregnes. Docker stats loggen har hverken tidsstempel eller fast logninginterval, hvorfor tallene/graferne kun kan bruges som en generel betragtning over hele test perioden.
I det nedenstående kan man klikke på de enkelte grafer for større billede. De enkelte iterationer er tegnet ind som lodrette mørke streger; 2 streger per iteration (start og slut tidspunkt).
Scope og afvikling
Scope
Testene involverer følgende komponenter
- MinLog 2 service
- NSP kafka
- Galera MariaDB cluster
- NSP standard performance test framework
Versionen af MinLog2 og test frameworket varierer for hver test og fremgår nedenfor.
MinLog 2's overordnede arkitektur ses af følgende figur (kilde: arkitektur dokumentet)
Lookup/forespørgsler test vedrører kun "lookup" komponenten, da der ingen opdateringer (registration ) foregårimens, og der dermed heller ingen aktivitet er på "consumer" komponenten. Dette betyder konkret, at de vedlagte log filer, som vedrører "consumer" komponenten ikke analyseres.
Afvikling
Performance testen er afviklet på følgende måde
- Testen er kørt på et test system opsat at Netic
- Testen er lavet i standard NSP performance frameworket, udviklet af Arosii i JMeter.
- Der er kørt en testplan med stadig øget belastning ved at øge antallet af tråde og noder indtil det målte throughput ikke længere vokser med tilsvarende mængde.
- Testplanerne kører 15 minutter per iteration og for læsning hentes 30 entries per side.
- System under test er kørt på 2 docker containere (docker01 og docker02 i nedenstående)
Se iøvrigt MinLog 2 test performancetestvejledning for detaljer.
Performance krav
Performance krav til MinLog 2 Performance test er som følger:
...
Svartider forespørgsler
...
| Children Display | ||
|---|---|---|
|
MinLog2 - Performancetest rapport borger lookup
Performance testen består af en række kald til opslag efter logninger på forskellige cpr numre. Et sådant enkelt opslag vil svare til, hvad en borger vil udføre, skulle han ville se hvad der er registreret om ham.
Testen udført er komponent "minlog2", testplan "lookupidws" og distribution "test900".
MinLog 2 service er version 2.0.25perf og NSP standard performance test framework version 2.0.21.
De rå test resultater er vedhæftet denne side (TODO)
JMeter log
JMeter hoved filen beskriver overordnet testens resultat. Her kan kan ses, at der er kørt 10 iterationer med test, deres tidsinterval , throughput og fejlprocent for hver.
...
Iteration
...
Tråde
...
Nodes
...
Starttid
...
Sluttid
...
Throughput
...
3
...
Det fremgår også af filen, at den endelige måling af throughput er 37,12 kald per sekund.
Samt at fejlprocentet på den fulde kørsel er 0 %.
Access log
Denne log findes for hver applikations server (docker container).
Her findes data for hvert enkelt kald, der er lavet til minlog servicen, herunder hvor lang tid et kald har taget (Duration) samt hvornår kaldet er udført. Ud fra loggens data kan man også beregne hvor mange kald der udføres i en given periode.
De følgende 2 grafer viser 95 % hendholdsvis 98 % percentil for kaldende. Grupperingen er 10 minutter:
Den næste graf viser antal kald per sekund:
Vurdering
TODO
Vmstat log
Denne log findes for hver applikations server (docker container). Den viser resultatet af kommandoen vmstat
Udtræk omkring cpu fra denne log vises i de følgende grafer:
Data serier i grafen er:
- cpuNonKernel (rød): tid brugt på non-kernel opgaver
- cpuKernel (blå): tid brugt på kernel opgaver
- cpuIdle (grøn): tid brugt på ingenting
- cpuWaitIO (gul): tid brugt på at vente på i/o
- iterationerne (sort) er en cirka placering, da wmstat loggen ikke indeholder tidstempel
Man kan se at cpuIdle og cpuNonKernel påvirkes lidt som servicen presses mere. cpuIdle ligger lavere over tid, mens cpuNonKernel grafen ligger en smule højere over tid. Den generelle flyt af kurverne er dog ikke faretruende.
Man kan også se, at cpuIdle dykker til 0 nogle få gange hen over iterationerne. Når dette sker er der en stigning i cpuKernal. Udsvingende vender dog retur til udgangspunktet.
Udtræk omkring io læs og skriv fra vmstat vises i de følgende grafer:
Data serier i grafen er:
- ioBlockRead (rød): læsning på disk (blokke)
- ioBlockWrite (blå): skriving på disk (blokke)
- iterationerne (sort) er en cirka placering, da wmstat loggen ikke indeholder tidstempel
Der er lidt løbende skriv til disken mens testen kører, og sammenligner man graferne fra før på cpu forbrug, ses det, at de få store udsving i skrivninger falder sammen med at cpuKernal går op og cpuIdle går ned.
Vurdering
TODO
Jstat log
Denne log findes for hver applikations server (docker container). Loggen viser resultatet af kommandoen jstat. Jstat siger noget om, hvordan JVM'en har det.
Udtræk omkring hukommelse og garbage collection fra denne log vises i de følgende grafer:
Data serier i grafen er:
- YGC (rød): young generation garbage collection events, antal af "ung" garbage collection siden start
- FGC (blå): full garbage collection events, antal af fuldstændig garbage collection siden start
- HeapU (gul): består af S0U+S1U+EU fra jstat loggen. Young generation memory utilization. "Ung" hukommelses forbrug
- HeapC (grøn): består af S0C+S1C+EC fra jstat loggen. Young generation memory capacity. "Ung" hukommelses kapacitet
- OU_MB (pink): old space utilization. "Ældre" hukommelses forbrug
- OC: old space capacity. "Ældre" hukommelses kapacitet er ikke en del af grafen men er konstant på 1.398.272 KB.
- Iterationer (sort) er baseret på det tidstempel, som findes i jstatloggen
Det kan være lidt svært at se graferne for full garbage collection (FGC). Kigger man nærmere på datagrundlaget bag graferne, ses det, at der ikke er full garbage collection for servicen under testen.
Der er en meget svag stigende tendens på den ældre hukommelse (OU_MB). Man må gå ud fra, at kommer den op på en kritisk grænse, da vil systemet køre en full garbage collection (FGC).
Der køres ofte garbage collection på den yngre hukommelse, hvilket holder HeapU - yngre hukommelses forbrug - nede så den kun svinger inden for et konstant interval.
Vurdering
TODO
Docker stats log
Denne log findes for hver applikations server (docker container). Loggen viser resultatet af kommandoen docker stats. Docker stats siger noget om, hvordan containeren forbruger sine ressourcer.
Udtræk omkring hukommelse, cpu og netværkstrafik vises i følgende grafer.
Hukommelse:
Data serier i grafen er:
- memoryUsage (rød): den totale mængde hukommelse containeren bruger
- memoryLimit (blå): den totale mængde hukommelse contaneren kan bruge
Den forbrugte hukommelse er meget stabil.
Cpu og hukommelse procent:
Data serier i grafen er:
- cpuPct (rød): hvor mange procent af hostens cpu containeren bruger
- memoryPct (blå): hvor mange procent af hostens hukommelse containeren bruger
Servicen viser et stabilt forbrug af hukommelse. Den envendte cpu er svagt stigende som servicen bliver presset.
Netværk:
Data serier i grafen er:
- netIn (rød): den mængde data som er modtaget af containeren over netværket
- netOut (blå): den mængde data som er sendt ud af containeren over netværket
De 2 grafer for ind- og udsendt data følges ad, hvilket er forventeligt; indkomne kald skaber trafik til database og igen retur til kalder. netOut stiger mest.
Vurdering
TODO
Konklusion
TODO
MinLog2 - Performancetest rapport medhjælper lookup
Performance testen består af en række kald til opslag efter logninger på forskellige cpr numre i medhjælper loggen. Et sådant enkelt opslag vil svare til en læge, der vil verificere hvilke logninger en given medhjælper har givet anledning til.
Testen udført er komponent "minlog2", testplan "lookup_onbehalfof" og distribution "test900".
MinLog 2 service er version 2.0.24perf og NSP standard performance test framework version 2.0.19
De rå test resultater er vedhæftet denne side (TODO)
Indledningsvis skal siges, at docker1 gik i fejl sidst i testen pga memory problemer. Der mangler derfor access log data for ca. 10 minutter i slutningen af testen.
JMeter log
JMeter hoved filen beskriver overordnet testens resultat. Her kan kan ses, at der er kørt 12 iterationer med test, deres tidsinterval , throughput og fejlprocent for hver.
...
Iteration
...
Tråde
...
Nodes
...
Starttid
...
Sluttid
...
Throughput
...
3
...
Det fremgår også af filen, at den endelige måling af throughput er 49.61 kald per sekund.
Samt at fejlprocentet på den fulde kørsel er 0,027 %.
Throughput falder mellem iteration 11 og 12. Man kunne overveje, om der er en relation mellem dette og den høje fejlprocent i iteration 12.
Access log
Vmstat log
Jstat log
Docker stats log
Konklusion
MinLog2 - Performancetest rapport minlog1 lookup
JMeter log
JMeter hoved filen beskriver overordnet testens resultat. Her kan kan ses, at der er kørt 4 iterationer med test, deres tidsinterval , throughput og fejlprocent for hver.
...
Iteration
...
Tråde
...
Nodes
...
Starttid
...
Sluttid
...
Throughput
...
3
...
Det fremgår også af filen, at den endelige måling af throughput er 69,49 kald per sekund.
Samt at fejlprocentet på den fulde kørsel er 0 %.
Access log
Vmstat log
Jstat log
Docker stats log
...