TBD:

Tjek "?" og se om rigtigt eller manglende
Hvad hedder young og old space på dansk? afsnittet omkring jstat skal justeres på denne baggrund
prøv at se grafer for lar container kørt med interval 1200 (ikke 900) . De har ligesom 4 runder
container grafer skal skiftes ud. interval kan ikke genberegnes. skal være enten 900 (1 linie pr sek) eller 1896 (hele loggen fordelt ud på 3 intervaller). Men ingen af dem kommer til at matche. What to do?
overvej om tabel i afsnit access log kun skal indeholde summer af alle app serverne og ikke fordelingen
[hvad kan man udlede af heapC op grafen for jstat???]
vurderinger for hver log fil
konklusion for hvert punkt nævnt først i afsnit "performance tal"

Scope

Performancetesten består af et antal kald til læsning af allergier for en liste af 50.000 personer (cpr numre).

Testen involverer følgende komponenter

LAR service som første led (v. 1.0.2)
CAVE service som andet led (v. 1.0.2)
FHIR database som tredie led (v. 3.7.0)
Derforuden har integrationen til minlog, MinSpæring og behandler relation check være aktiveret under kørslen (Herefter benævnt som MSB)

Performance krav

Kravene fra fra kravspecifikationen lyder som følger:

Systemets svartider måles på en klient i umiddelbar nærhed af LAR service snitfladen, således at der medregnes et netværkskald mellem klient og service.
Systemets gennemsnitlige svartid ved læsning skal ligge under 200ms.
Forudsætninger for ovenstående svartider er, at:
1. systemet anvendes af 10 samtidige brugere, der udfører et kald pr. sekund med 1000ms tidsmæssig forskydning på forskellige CPR numre.
2. databasen indeholder 50.000 allergi-registreringer på et tilsvarende antal patienter.
3. eksterne servicekald er deaktiveret
4. der er ikke andre services der anvender infrastrukturen.
5. der anvendes to applikationsservere til hver service, svarende til en NSP med to søjler til LAR servicen og to Back-End servere til CAVE servicen. Servicekald fordeles efter Round-Robin princippet mellem hver af de to servere.
6. Serverne er hardwaremæssigt konfigureret svarende til NSP applikationsservere.

Kommentarer

???
Dette vil bleve vurderet med udgangspunkt i test resultaterne
Forudsætnigner
1. NSP standard test framework vil blive brugt. Belasningen vil derfor lægge højere end 10 samtidige brugere. Der startes med 2 noder med 7 tråde. Dvs. 14 brugere.
2. inden testen startes er en database med 50.000 allergier fordelt på 50.000 patiener klargjort
3. de eksterne servicekald var aktiveret under kørslen. Da svartiderne for disse kan findes i log filerne kan der laves en beregning, der viser svartiderne uden de eksterne servicekald.
4. ???
5. der er ialt anvendt 4 søjler, hvor LAR og CAVE har kørt på alle 4.
6. ???

Afvikling

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

der er anvendt et test certifikat. Og der trækkes et idkort i setup fasen af testen, dvs hver gang en node startes på. Den del er holdt ude af performance målingen
testen er kørt på test system opsat at Netic: cstag-lb.cnsp.netic.dk:8080
testen er lavet i standard NSP performance frameworket (v.2.0.0), 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.
Testplanen der er kørt er test900, og den er kører 15 minutter per iteration.
System under test (LAR og CAVE servicen) er kørt på på 4 docker containere
Kald til de 3 eksterne service MSB har været aktiveret under testen

Se iøvrigt LAR test vejledning afsnit 2.3 performance test for detaljer.

De rå test resultater er vedhæftet denne side (lar-cave-perftest.tgz)

Performance tal

Udover det fremsatte performance krav med en svartid på under 200 ms, 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

Disse undersøges 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 test runder kørt
- Throughput
- (/stress01.nsp-test.netic.dk-lar/lar_listallergy_test900_stress01.nsp-test.netic.dk_master_20190513_114050.tar.gz.log)
Access log og sla log (applikations server information) belyser
- Antal kald per sekund
- Svartid per kald
- (Ex: docker01.cnsp.stage.nsp.netic.dk-lar/logs/lar/access.log)
vmstat log (system information) belyser
- cpu status
- Logning sker hver 10. sekund
- (Ex: docker01.cnsp.stage.nsp.netic.dk-lar/stats/docker01.cnsp.stage.nsp.netic.dk-cpu-20190513110936.log)
jstat log (JVM information) belyser
- Hukommelse (heap) forbrug
- Garbage collection
- Tidsstempel per log linie
- (Ex: docker01.cnsp.stage.nsp.netic.dk-lar/stats/docker01.cnsp.stage.nsp.netic.dk-cave-jstat-20190513110936.log)
docker stats log (container information) belyser
- Hukommelse
- io på netværk
- Logning sker hvert sekund
- (Ex: docker01.cnsp.stage.nsp.netic.dk-lar/stats/docker01.cnsp.stage.nsp.netic.dk-cave-container-20190513110936.log)

Hver kørsel/runde (ø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 runde. Filerne vmstat og docker stats har ikke tidstempler. Men da disse er startet samtidig med jstat loggen og logintervallet er kendt, kan runderne placering i data beregnes.

Hvor der i nedenstående er grupper af 4 grafer, skal de læses fra venstre mod højre og ned og mod højre: dette viser app server 1, 2, 3 og 4. Klik på den enkelt graf for større billede. De enkelte runder er tegnet ind som lodrette mørke streger; 4 streger der sympolisere de 3 runder start og slut.

JMeter log data

JMeter hoved filen beskriver overordnet testens resultet.

Her kan kan ses, at der er kørt 3 runder med test, deres tidsinterval og throughput for hver.

Runde	Tråde	Nodes	Starttid	Sluttid	Throughput
1	7	2	2019-05-13_11-10-14	2019-05-13_11-25-18	20,42 kald per sekund
2	10	2	2019-05-13_11-25-41	2019-05-13_11-40-44	20,84 kald per sekund
3	10	3	2019-05-13_11-41-12	2019-05-13_11-56-17	25,09 kald per sekund

Det fremgår også af filen, at den endelige måling af throughput er 25,09 kald per sekund.

Samt at fejlprocentet på den fulde kørsel er 0,01 %.

Vurdering

Kravet til testen er, at der skal køres med 10 samtidige brugere med hver et kald per sekund. NSP's test framework fungerer med en bestemt belastning i testen som gradvis øges.

Testen har kørt med i første runde 14 samtidige brugere, anden runde 20 brugere og sidste runde 30 brugere. Hvilket ligger over kravet til testen. Da testen også har kørt med MSB servicen aktiveret har det lagt yderligere pres på testen.

Derfor konkluderes at ud fra JMeter loggens data ser testens resultat fornuftig ud i forhold til performance kravet.

Access log data

Denne log findes for hver applikations server (docker container) for både LAR og CAVE servicen.

Her findes data for hvert enkelt kald, der er lavet til de 2 LAR og CAVE services, herunder hvor lang tid et kald har taget (Duration). Ved at kigge på de kald, der er foretaget til LAR servicen kan den gennemsnitlige tid et kald tager beregnes.

Desuden kan tidsforbruget for kald til MSB servicene findes via via servicenes sla logs (nsputil-sla-lar.log) og messageid, og på den måde trækkes fra LAR servicens tid for at få netto tiden.

Følgende tabel viser en række beregnede data fra access loggen fordelt på applikations server (container), testrunde og http kode. Nederst i tabellen er tallene for hver applikations server lagt sammen. Testrunde er beregnet ved at sammenligne tidstempel fra access log med start og sluttidspunktet for runden. http koden findes i access loggen (kald returnerede med fejl (500) eller ingen fejl(200)).

De beregnede data er antal kald, kald per sekund i gennemsnit (hver runde er 900 sekunder), tidsforbrug per kald i millisekunder.

Applikations server	Runde	HttpCode svar	Antal kald	Kald per sekund	Tidsforbrug (ms)
Applikations server	Runde	HttpCode svar	Antal kald	Kald per sekund	Med MSB	Uden MSB
docker01.cnsp.stage.nsp.netic.dk-lar/	1	200	4597	5,1	623	154
	2	200	4693	5,2	868	177
	3	200	5650	6,3	1123	206
		500	1	0	32257	32189
docker02.cnsp.stage.nsp.netic.dk-lar/	1	200	4597	5,1	612	149
	2	200	4693	5,2	900	193
	3	200	5650	6,3	1125	197
		500	1	0	31634	31579
docker03.cnsp.stage.nsp.netic.dk-lar/	1	200	4598	5,1	620	153
	2	200	4693	5,2	885	173
	3	200	5650	6,3	1114	185
		500	1	0	33109	32917
docker04.cnsp.stage.nsp.netic.dk-lar/	1	200	4598	5,1	624	162
	2	200	4692	5,2	904	192
	3	200	5652	6,3	1124	197
Total			59766		896	181

Total for alle 4 servere	1	200	18390	20,4	620	155
	2	200	18771	20,9	889	184
	3	200	22602	25,1	1122	196
	3	500	3	0	32333	32228

Vurdering

Af tabellen fremgår det, at jo flere brugere (brugere øges per runde) jo flere kald kommer der igennem per sekund. Tallene svarer overens med de tal JMeter kom frem til som throughput.

Det ses, at jo flere brugere jo højere bliver svar tiden. Performance kravet er 200 ms ved 10 brugere uden MSB services slået til. Ovenstående tabel viser, at ved 14 brugere (runde 1) er svartiden 155 ms. Vi er inden for performance kravet.

Man kan undres over, hvorfor det skal tages så meget mere tid når MSB servicene medtages. Det har vist sig at kaldet til BRS er lavet uhensigtmæssigt, hvilket bliver rettet på Jira CAVE-78. Dette burde give bedre performance.

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 4 grafer.

De 4 data serier i grafen er:

cpuNonKernel: tid brugt på non-kernel opgaver
cpyKernel: tid brugt på kernel opgaver
cpuIdle: tid brugt på ingenting
cpuWaitIO: tid brugt på at vente på i/o
De 3 runder er en cirka placering, da wmstat loggen ikke indeholder tidstempel

De 4 dataserier i graferne er meget stabile. Man fornemmer aktivitet omkring start og slut af de 3 runder. Størst udsving er der ved opstart af testen, hvor den cpu der bliver brugt af applikationen (cpuNonKernel) striger meget og idle cpu tilsvarende falder. Men det er kun kortvarigt.

Vurdering

Graferne ser fornuftige ud. Der er intet at bemærke omkring cpu forbrug.

Jstat log

Denne log findes for hver applikations server (docker container) - en for LAR og en for CAVE. 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 4 grafer for henholdsvis LAR og CAVE.

LAR servicen:

CAVE servicen:

De 5 data serier i grafen er:

YGC: young generation garbage collection events, antal af ung generation garbage collection siden start
FGC: full garbage collection events, antal af fuldstændig garbage collection siden start
HeapU: består af S0U+S1U+EU fra jstat loggen. Young generation memory utilization. Ung hukommelses forbrug
HeapC: består af S0C+S1C+EC fra jstat loggen. Young generation memory capacity. Ung hukommelses kapacitet
OU_MB: 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 for både LAR og CAVE.
De 3 runder er baseret på det tidstempel, som findes i jstatloggen

For LAR kan man se, at der er kørt et par enkle fuld garbage collections. Ved start af runde 1 og midt i runde 3. For CAVE kan man se, at der ikke er kørt fuld garbage collection. Der køres også oftere garbage collection på den unge hukommelse på LAR servicen end der gør på CAVE.

Den brugte unge hukommelse svinger noget for både LAR og CAVE, men dog i et konstant interval.

Vurdering

Den unge forbrugte hukommelse eskalerer ikke for hverken LAR eller CAVE. Dog øges den ældre hukommelse over tid for LAR servicen.

Docker stats log

Denne log findes for hver applikations server (docker container) - en for LAR og en for CAVE. Loggen viser resultatet af kommandoen docker stats. Docker stats siger noget om, hvordan containeren forbruger sine ressourcer.

Udtræk omkring hukommelse, cpu netværkstrafik vises i følgende 3 * 4 grafer.

LAR service - Hukommelse:

CAVE service - Hukommelse:

De 2 data serier i grafen er:

memoryUsage: den totale mængde hukommelse containeren bruger
memoryLimit: den totale mængde hukommelse contaneren kan bruge
De 3 runder er en cirka placering, da docker stats loggen ikke indeholder tidstempel

Den forbrugte hukommelse for CAVE servicen er meget stabil. For LAR servicen er den svagt stigende.

LAR service - Cpu og hukommelse procent:

CAVE service - Cpu og hukommelse procent:

De 2 data serier i grafen er:

cpuPct: hvor mange procent af hostens cpu containeren bruger
memoryPct: hvor mange procent af hostens hukommelse containeren bruger
de 3 runder er en cirka placering, da docker stats loggen ikke indeholder tidstempel

Begge procenter er stabil for CAVE servicen. LAR servicen viser et stigende forbrug af hukommelse.

LAR service - netværk

CAVE service - Netværk:

De 2 data serier i grafen er:

netIn - den mængde data som er modtaget af containeren over netværket
netOut - den mænde data som er sendt ud af containeren over netværket
de 3 runder er en cirka placering, da docker stats loggen ikke indeholder tidstempel

De 2 grafer for ind- og udsendt data følges pænt, hvilket er forventeligt

Vurdering

Placeringen af rundernes markering kunne umiddelbart godt se forkert ud når man generelt ser på graferne. Der er ændret adfærd ca. 150 enheder før den angivne markering første gang, og den bliver længere og længere til venstre.

Derforuden...

Konklusion

TBD

Fejlprocess vurdering,

tjek evt. de 500 kald, hvorfor de optod