Versions Compared

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

...

For alle test gælder følgende:

Udover det de fremsatte performance krav på svartid, er der en række andre punkter, som bør analyseres for at vurdere servicens sundhed.

...

  • Svartid per kald
  • Antal kald per sekund
  • Cpu status
  • io på netværk
  • Hukommelses forbrug
  • Garbage collection

...

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)

...

Lookup/forespørgsler test vedrører kun "lookup" komponenten, da der ingen opdateringer (registration ) foregår imens, og der dermed heller ingen aktivitet er på "consumer" komponenten.  Dette betyder konkret, at de vedlagte tilsendte log filer, som vedrører "consumer" komponenten ikke analyseres.

Der er ikke målinger på database serveren (MariaDB).

Afvikling

Performance testen er afviklet på følgende måde

...

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.

...

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. 

...

Vi er inden for performance kravene i testen testens fulde køretid.

Vmstat log

Denne log findes for hver applikations server (docker container). Den viser resultatet af kommandoen vmstat

...

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.

...

Indledningsvis skal siges, at servicen kørende på docker1 gik i fejl sidst i testen pga memory problemer. Der mangler derfor access log data for ca. 10 minutter i slutningen af testen.

...

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. 

...

Af grafen fremgår det, at jo flere nodes og tråde (disse øges over tid, per iteration) jo flere kald kommer der igennem per sekund overordnet set.

Servicen kørende på Docker1, som fik problemer sidst i testen, har dog et faldende antal request i sidste iteration.

...

Vi er inden for performance kravene i testen fulde køretid, selv i den test iteration, hvor den ene test testede service stoppede.

Vmstat log

...

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. 

Hen ved testens 10. iteration sker der dog en stor ændring i dette mønster. Her stiger cpuNonKernal meget fra at ligge under 50 % til at komme over. For docker1 docker1s vedkommende bliver den ved at stige, til den rammer næsten 100 %, og for docker2 lander den på 85%

...

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. Dog ses en markant stigning i antal af skriv til disk i samme periode som cpuNonKernel stiger.

...

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

Disse log data viser igen den øgede cpu og hukommelsesforbrug sidst i testen. Det ser dog ud til at containeren har masser af hukommelse og ikke i sig selv er ved at løbe tør.

Konklusion

Efter at have analyseres data fra performance testen kan følgende trækkes frem:

  • Throughput på testen er 49,61 kald per sekund

  • Gennemsnitlig højeste svartid per kald til servicen: 
    For 95 % percentil: under 2,1 sekunder
    For 98 % percentil: under 2,5 sekunder
    Kravene på under 2,5 henholdsvis 5,5 sekunder er overholdt

  • Cpu status: servicen ser ud til at få problemer med cpu forbruget når den presses

  • io på netværk: stiger over tid, hvilket er forventet

  • Hukommelses forbrug: servicen ser ud til at få problemer med hukommelsen når den presses

  • Garbage collection: servicen kører jævnligt garbage collection. Noget kunne tyde på, at når servicen bliver presset, kan garbage collection ikke helt få ryddet op.

Performance testen er designet til at presse en service mere og mere. Medhjælper lookup viser en svaghed, når den presses og når til iteration 10, som er 10 tråde og 2 nodes. Det bør undersøges, hvordan denne belastning ligger i forhold til, hvad der forventes i drift, for at vurdere, om det vil blive et faktisk problem.

Den kraftige forøgelse af cpu og hukommelses forbrug bør undersøges. Kombinationen kunne måske tyde på loop. Dette bør undersøges nærmere i andre log filer eller en fokuseret test rettet mod dette.

Da testen bliver afbrudt i mangel på hukommelse, viser den ikke, om vi faktisk har nået det maksimale

...

throughput den ellers ville have kunnet yde. Allokering af mere hukommelse til servicen kunne afhjælpe dette.

De mange fejl, der ses i jmeter loggen kan skyldes at servicen på docker1 stopper med at svare og dermed melder "Internal Server Error" tilbage.

MinLog2 - Performancetest rapport minlog1 lookup

...