Dette dokuement beskriver performance test og analyse for

NAS 2 notification broker service
NAS 2 pull point service

Performance analyse

For begge test gælder følgende:

Udover det fremsatte performance krav for notification broker henholdsvis pull point 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

Da NAS servicene ikke skriver til disk selv, bliver io til disk ikke undersøgt. Der er ikke målinger på database serveren (MariaDB). Der er målinger fra Kafka serverne.

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/nas_notificationbroker_nbtest900_stress01.nsp-test.netic.dk_master_20191007_122321.tar.gz.log)
Access log (applikations server information) belyser
- Antal kald per sekund
- Svartid per kald
- (Ex: docker01.bo.stage.nsp.netic.dk-perflogs/nas/notificationbroker/access.log)
vmstat log (system information) belyser
- cpu status
- skrivning til disk
- Logning sker hver 10. sekund
- (Ex: docker01.bo.stage.nsp.netic.dk-perflogs/docker01.bo.stage.nsp.netic.dk-vmstat-20191007111959.log)
jstat log (JVM information) belyser
- Hukommelse (heap) forbrug
- Garbage collection
- Der er tidsstempel per log linie
- (Ex: docker01.bo.stage.nsp.netic.dk-perflogs/docker01.bo.stage.nsp.netic.dk-docker-jstat-gc-stage_bo_comp_nas_notificationbroker.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-perflogs/docker01.bo.stage.nsp.netic.dk-stage_bo_comp_nas_notificationbroker-20191007112000.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).

Notification Broker

Scope

Performance testen består af en række kald til skrivning af adviseringer.

Testen involverer følgende komponenter

NAS 2 Notification Broker service version 2.0.6
NSP kafka
Gallera MariaDB cluster
NSP standard performance test framework version 2.0.10

Performance krav

Performancekravene er som følger:

Forudsætninger:
1. Test: 10 adviseringer per sekund (1 advisering per kald)
Krav:
1. Gennemsnitlig svartid skal være under 250 millisekunder
2. 95 % skal være under 500 millisekunder

Kommentarer til forudsætninger og krav

NSP standard test frame work anvendes, hvor belastningen gradvis øges fra 2 nodes og 5 tråde. Kravet om 10 adviseringer per sekund kan omsættes til et throughput på 10 kald per sekund, hvilket kan vurderes vha. NSP test frameworkets output.
Krav til svartider vil blive vurderet med udgangspunkt i test resultaterne.

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 (v.2.0.10), 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 nbtest900, og den kører 15 minutter per iteration.
System under test er kørt på på 2 docker containere
Den anvendte kafka har kørt på 3 docker containere

Se iøvrigt NAS2 test vejledning afsnit performance test for detaljer.

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

Performance tal

Der er kun kigget på performance målinger/tal, der vedrører selve notification broker servicen.

JMeter log data

JMeter hoved filen beskriver overordnet testens resultet.

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

Iteration	Tråde	Nodes	Starttid	Sluttid	Throughput
1	5	2	2019-10-07_11-21-21	2019-10-07_11-36-25	399.36 kald per sekund
2	8	2	2019-10-07_11-36-54	2019-10-07_11-51-57	523.03 kald per sekund
3	8	3	2019-10-07_11-52-27	2019-10-07_12-07-31	719.42 kald per sekund
4	8	4	2019-10-07_12-08-06	2019-10-07_12-23-09	910.14 kald per sekund
5	8	5	2019-10-07_12-24-30	2019-10-07_12-39-33	1010.45 kald per sekund

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

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

Vurdering

Kravet til testen er, at der skal køres med 10 adviseringer i sekundet. NSP's test framework fungerer med en bestemt belastning i testen som gradvis øges. I første iteration har testen kørt med 400 kald per sekund, hvilket ligger højt over kravet til testen.

Derfor konkluderes det, at ud fra JMeter loggens data, er performance kravets forudsætning om 10 adviseringer så rigeligt overholdt.

Access log data

Denne log findes for hver applikations server (docker container).

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

Følgende tabel viser en række beregnede data fra access loggen fordelt på applikations server (container), test iteration og http kode. Nederst i tabellen er tallene for hver applikations server lagt sammen. Test iteration er beregnet ved at sammenligne tidstempel fra access log med start og sluttidspunktet for iterationen. 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 iteration er 900 sekunder), gennemsnitlig tidsforbrug per kald i millisekunder samt antal kalder større eller lig med 500 millisekunder.

Applikations server	Iteration	HttpCode svar	Antal kald	Kald per sekund	Tidsforbrug (ms)	Kald >= 500 ms
docker01.bo.stage.nsp.netic.dk	1	200	179.830	199,8	9	38 (0 %)
	2	200	235.357	261,5	11	70 (0 %)
	3	200	324.407	360,5	13	87 (0 %)
	4	200	409.904	455,4	14	117 (0 %)
	5	200	454.973	505,5	16	179 (0 %)
docker02.bo.stage.nsp.netic.dk	1	200	179.831	199,8	10	30 (0 %)
	2	200	235.356	261,5	11	69 (0 %)
	3	200	324.406	360,5	13	87 (0 %)
	4	200	409.904	455,4	14	95 (0 %)
	5	200	454.982	505,5	15	158 (0 %)

Udtræk af svartid og antal kald fordelt over testens løbetid vises i følgende grafer:

NSP services > NAS2 - performancetests > duration1_GraphAdjDurationInterval_intDurationAverage_Graph.png

Data serier i grafen er:

DurationAverage (rød): den gennemsnitlige svartid (ms) for hvert minut
Iterationer (sort) er baseret på det tidstempel, som findes i loggen

NSP services > NAS2 - performancetests > duration1_GraphAdjDurationInterval_intNoOfCalls_Graph.png

Data serier i grafen er:

NoOfCalls (rød): det gennemsnitlige antal kald hvert minut
Iterationerne (sort) er baseret på det tidstempel, som findes i loggen

Vurdering

Af tabel og grafer fremgår det, at jo flere nodes og tråde (disse øges per iteration) jo flere kald kommer der igennem per sekund. Tallene svarer overens (summen for de 2 servere) med de tal JMeter kom frem til som throughput.

Det ses (tydligst i tabellen), at jo flere nodes/tråde jo højere bliver svar tiden. Performance kravet er under 250 ms i gennensnit ved 10 adviseringer per sekund. Ovenstående tabel viser, at ved iteration 1 er svartiden 9 ms, og tidligere fremgik det at througput her var 400 kald per sekund.

Tabellen ovenfor viser også, at det antal kald, der tager mere end 500 ms er så lavt, at kravet med, at 95 % skal være under 500 ms, er overholdt.

Vi er inden for performance kravene.

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.

NSP services > NAS2 - performancetests > vmstat1_GraphVmStatCpu_cpuNonKernel_cpuKernel_cpuIdle_cpuWaitIO_Graph.png

Data serier i grafen er:

cpuNonKernel (rød): tid brugt på non-kernel opgaver
cpyKernel (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 som servicen presses mere. cpuIdle svinger oftere mod 0 i de sidste 2 iterationer. Det er dog vigtigt at bemærke at det kun er kortvarigt og cpyIdle går op igen.

Vurdering

Der er intet negativt at bemærke omkring cpu forbruget.

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 er kørt ikke er full garbage collection for servicen under testen.

Der køres også ofte garbage collection på den yngre hukommelse, hvilket holder HeapU - yngre hukommelses forbrug - nede så den kun svinger inden for et konstant interval.

Vurdering

Den yngre forbrugte hukommelse eskalerer ikke. Garbage collecteren gør sit arbejde.

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 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 svagt stigende, men da jstat statistikken ikke indikerer at selve applikationen øger forbruget af hukommelse, anses det ikke som et problem.

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 svagt stigende forbrug af hukommelse, men som skrevet for forrige graf anses det ikke som et problem. Den envendte cpu er 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ænde data som er sendt ud af containeren over netværket

TBD

Vurdering

Intet at bemærke.

Kafka statistik

De følgende grafer er lavet på baggrund af vmstat data på kafka serveren.

NSP services > NAS2 - performancetests > vmstatDB1_GraphVmStatCpu_cpuNonKernel_cpuKernel_cpuIdle_cpuWaitIO_Graph.png

Data serier i grafen er:

cpuNonKernel (rød): tid brugt på non-kernel opgaver
cpyKernel (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

Der er et meget svagt fald i Cpu Idle som testen skrider frem. Men den ligger generelt højt, så der er masser af cpu tid til rådighed.

NSP services > NAS2 - performancetests > vmstatDB1_GraphVmStatCpu_ioBlockRead_ioBlockWrite_Graph.png

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

Skrivning øges som kaldende intensiveres. Læsning er meget begrænset, hvilket må betyde at data læses fra cachen.

Vurdering

Der er intet at bemærke som kan påvirke nas servicens performance i negativ retning.

Konklusion

Pull Point

Scope

Performance testen består af en række kald til læsning af pull points.

Testen involverer følgende komponenter

NAS 2 Pull Point service version 2.0.6
NAS 2 Notification Broker service version 2.0.6 (baggrundsbelastning)
NSP kafka
Gallera MariaDB cluster
NSP standard performance test framework version 2.0.10

Performance krav

Performancekravene er som følger:

Forudsætninger:
1. Baggrundsdata:
  1. 1 topic
  2. 1.000 pullpoints på dette topic (20 af disse bruges aktivt under testen)
  3. Hver pullpoint har en unik idliste med hver 3000 id'er
  4. Der behøver ikke være beskeder på tipic inden testen starter
2. Baggrundsbelastning
  1. Notifikation broker skal lave 40 adviseringer per sekund fordelt ligeligt på 20 udvalgte pullpoints
  2. Dvs. 2 adviseringer per pullpoint per sekund
3. Test: 1 kald til getMessage på hver af de 20 udvalgte pullpoints hver 10. sekund. Dvs. 2 kald per sekund
Krav:
1. Gennemsnitlig svartid skal være under 5.000 millisekunder
2. 95 % skal være under 10.000 millisekunder
3. 99 % skal være under 20.000 millisekunder

Kommentarer til forudsætninger og krav

Forudsætninger
1. De omtalte baggrundsdata er til stede i form af et database script, der er indlæst inden opstart af test
2. Baggrundsbelastningen er til stede i form at et baggrundsjob der skriver til Notification broker
3. Som for notification broker testen anvendes NSP standard framework, hvor et throughput på 2 kald per sekund kan vurderes
Krav til svartider vil blive vurderet med udgangspunkt i test resultaterne.

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 (v.2.0.10), 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 pptest900, og den kører 15 minutter per iteration.
System under test er kørt på på 2 docker containere
Den anvendte kafka har kørt på 3 docker containere

Se iøvrigt NAS2 test vejledning afsnit performance test for detaljer.

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

Performance tal

Der er kun kigget på performance målinger/tal, der vedrører selve pull point servicen.

JMeter log data

JMeter hoved filen beskriver overordnet testens resultet.

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

Iteration	Tråde	Nodes	Starttid	Sluttid	Throughput
1	5	2	2019-10-04_14-25-44	2019-10-04_14-40-50	53.48 kald per sekund
2	8	2	2019-10-04_14-41-29	2019-10-04_14-56-35	90.4 kald per sekund
3	11	2	2019-10-04_14-57-15	2019-10-04_15-12-21	109.17 kald per sekund
4	11	3	2019-10-04_15-13-01	2019-10-04_15-28-08	111.07 kald per sekund

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

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

Vurdering

Kravet til testen er, at der skal køres med 20 kald til pull point servicen hver 10. sekund dvs. 2 per sekund. NSP's test framework fungerer med en bestemt belastning i testen som gradvis øges. I første iteration har testen kørt med 53 kald per sekund, hvilket ligger højt over kravet til testen.

Derfor konkluderes det, at ud fra JMeter loggens data, er performance kravets forudsætning om 2 kald så rigeligt overholdt.

Access log data

Denne log findes for hver applikations server (docker container).

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

Følgende tabel viser en række beregnede data fra access loggen fordelt på applikations server (container), test iteration og http kode. Nederst i tabellen er tallene for hver applikations server lagt sammen. Test iteration er beregnet ved at sammenligne tidstempel fra access log med start og sluttidspunktet for iterationen. 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 iteration er 900 sekunder), gennemsnitlig tidsforbrug per kald i millisekunder samt antal kalder større eller lig med 500 millisekunder.

Applikations server	Iteration	HttpCode svar	Antal kald	Kald per sekund	Tidsforbrug (ms)	Kald >= 10.000 ms
docker01.bo.stage.nsp.netic.dk	1	200	24.075	26,8	148	0 (0 %)
	2	200	40.705	45,2	136	0 (0 %)
	3	200	49.131	54,6	141	0 (0 %)
	4	200	50.034	55,6	141	0 (0 %)
docker02.bo.stage.nsp.netic.dk	1	200	24.074	26,7	151	0 (0 %)
	2	200	40.705	45,2	142	0 (0 %)
	3	200	49.131	54,6	148	0 (0 %)
	4	200	50.036	55,6	148	0 (0 %)

Udtræk af svartid og antal kald fordelt over testens løbetid vises i følgende grafer:

NSP services > NAS2 - performancetests > duration1_GraphAdjDurationInterval_intDurationAverage_Graph.png

Data serier i grafen er:

DurationAverage (rød): den gennemsnitlige svartid (ms) for hvert minut
Iterationer (sort) er baseret på det tidstempel, som findes i loggen

NSP services > NAS2 - performancetests > duration1_GraphAdjDurationInterval_intNoOfCalls_Graph.png

Data serier i grafen er:

NoOfCalls (rød): det gennemsnitlige antal kald hvert minut
Iterationer (sort) er baseret på det tidstempel, som findes i loggen

Vurdering

Af tabel og grafer fremgår det, at jo flere nodes og tråde (disse øges per iteration) jo flere kald kommer der igennem per sekund. Tallene svarer overens (summen for de 2 servere) med de tal JMeter kom frem til som throughput.

Derimod har svar tiden ved en øgning af nodes/tråde en nogenlunde konstant gennemsnits svartid. Den øges ikke som det ses ved notification broker testen.

Performance kravet er under 5.000 ms i gennensnit ved 2 kald per sekund. Ovenstående tabel viser, at ved iteration 1 er svartiden ca 150 ms, og tidligere fremgik det at througput her var 153 kald per sekund.

Tabellen ovenfor viser også, at det antal kald, der tager mere end 10.000 ms er 0, og dermed er kravet med, at 95 % skal være under 10.000 ms, overholdt. Og dermed også kravet om 99 % skal være under 20.000 ms.

Vi er inden for performance kravene.

Baggrundsbelastning

Ved at kigge i access loggen for notification broker under pull point testen, kan kald til notification broker ses.

NSP services > NAS2 - performancetests > duration_notificationbroker_1_GraphAdjDurationInterval_intNoOfCalls_Graph.png

Data serier i grafen er:

NoOfCalls (rød): det gennemsnitlige antal kald hvert minut
Iterationer (sort) er baseret på det tidstempel, som findes i loggen

Hver minut kaldes hver server ca. 1200 gange.

Kigger man ned i access loggen kan fordelingen af pull point trækkes ud.

Følgende tabel viser antal af pull point fordelt per iteration, hvor de er ligeligt fordelt.

Pull point	iteration 1	iteration 2	iteration 3	iteration 4
pullPoint0001	1789	1790	1789	1790
pullPoint0002	1789	1790	1789	1790
pullPoint0003	1789	1790	1789	1790
pullPoint0004	1789	1790	1789	1790
pullPoint0005	1789	1790	1789	1790
pullPoint0006	1789	1788	1789	1790
pullPoint0007	1789	1790	1788	1790
pullPoint0008	1789	1790	1788	1790
pullPoint0009	1789	1790	1788	1790
pullPoint0010	1788	1790	1788	1790
pullPoint0011	1788	1790	1788	1790
pullPoint0012	1788	1790	1788	1790
pullPoint0013	1788	1790	1788	1790
pullPoint0014	1788	1789	1788	1790
pullPoint0015	1788	1789	1788	1790
pullPoint0016	1788	1787	1788	1789
pullPoint0017	1788	1789	1788	1790
pullPoint0018	1788	1785	1788	1789
pullPoint0019	1788	1789	1788	1789
pullPoint0020	1788	1789	1788	1789
Total	35769	35785	35766	35796

Følgende tabel viser antal af pull point fordelt per sekuend på 6 på hinanden tilfældige sekunder på tværs af server (stik prøve). Fordelingen er ligeligt fordelt med enkelt afvigelse der justeres i sekundet efter.

Pull point	14:25:59	14:26:00	14:26:01	14:26:02	14:26:03	14:26:04
pullPoint0001	2	2	2	2	2	2
pullPoint0002	2	2	0	4	2	2
pullPoint0003	2	2	2	2	2	2
pullPoint0004	2	2	2	2	2	2
pullPoint0005	0	4	2	2	2	2
pullPoint0006	2	2	2	2	2	2
pullPoint0007	2	2	2	2	2	2
pullPoint0008	2	2	2	2	2	2
pullPoint0009	2	2	2	2	2	2
pullPoint0010	2	2	2	2	2	2
pullPoint0011	2	2	2	2	2	2
pullPoint0012	2	2	2	2	2	2
pullPoint0013	2	2	2	2	2	2
pullPoint0014	2	2	0	4	2	2
pullPoint0015	2	2	2	2	2	2
pullPoint0016	0	4	2	2	2	2
pullPoint0017	2	2	2	2	2	2
pullPoint0018	2	2	2	2	2	2
pullPoint0019	2	2	2	2	2	2
pullPoint0020	2	2	2	2	2	2

Vurdering

Kravet til baggrundsbelastningen for testen er, at der skal laves 40 adviseringer per sekund fordelt ligeligt på 20 udvalgte pullpoints. Det svarer til 2400 kald per minut, hvilket ovenstående grafer viser er sket fordelt på 2 servere.

Desuden rammer kaldene ligeligt de 2 pull points per iteration og per sekund i stikprøven.

Det konkluderes ud fra ovenstående, at ud fra access loggens data for notification broker, er performance kravets forudsætning om mængden af baggrundsbelastning overholdt.

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.

NSP services > NAS2 - performancetests > vmstat1_GraphVmStatCpu_cpuNonKernel_cpuKernel_cpuIdle_cpuWaitIO_Graph.png

Data serier i grafen er:

cpuNonKernel (rød): tid brugt på non-kernel opgaver
cpyKernel (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

De dataserierne i graferne er meget stabile, med et par enkelte peaks.

Vurdering

Der er intet negativt at bemærke omkring cpu forbruget.

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.

NSP services > NAS2 - performancetests > jstatPullPoint1_GraphJStat_YGC_FGC_HeapC_HeapU_OU_MB_Graph.png

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 er kørt ikke er full garbage collection for servicen under testen.

Der køres også ofte garbage collection på den yngre hukommelse, hvilket holder HeapU - yngre hukommelses forbrug - nede så den kun svinger inden for et konstant interval.

Vurdering

Den yngre forbrugte hukommelse eskalerer ikke. Garbage collecteren gør sit arbejde.

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 netværkstrafik vises i følgende grafer.

Hukommelse:

NSP services > NAS2 - performancetests > containerPullPoint1_GraphContainer_memoryUsage_memoryLimit_Graph.png

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:

NSP services > NAS2 - performancetests > containerPullPoint1_GraphContainer_cpuPct_memoryPct_Graph.png

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:

NSP services > NAS2 - performancetests > containerPullPoint1_GraphContainer_netIn_netOut_Graph.png

Data serier i grafen er:

netIn (rød): den mængde data som er modtaget af containeren over netværket
netOut (blå): den mænde data som er sendt ud af containeren over netværket

TBD

Kafka statistik

De følgende grafer er lavet på baggrund af vmstat data på kafka serveren.

NSP services > NAS2 - performancetests > vmstatDB1_GraphVmStatCpu_cpuNonKernel_cpuKernel_cpuIdle_cpuWaitIO_Graph.png

Data serier i grafen er:

cpuNonKernel (rød): tid brugt på non-kernel opgaver
cpyKernel (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

Der er et meget svagt fald i Cpu Idle som testen skrider frem. Men den ligger meget højt generelt, så der er masser af cpu tid til rådighed.

NSP services > NAS2 - performancetests > vmstatDB1_GraphVmStatCpu_ioBlockRead_ioBlockWrite_Graph.png

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 en jævn skriving til disk som testen skrider frem. Dette skyldes den konstante baggrundsbelastning fra notification broker. Læsning er meget begrænset, hvilket må betyde at data læses fra cachen.

Vurdering

Der er intet at bemærke som kan påvirke nas servicens performance i negativ retning.

Konklusion

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

Svartid per kald til servicen: 150 ms for 2 nodes og 5 tråde, og med et throughput på 53 kald per sekund
Kravet er, at et kald skal tage mindre end 5.000 ms med 1 kald på 20 pullpoints hvert 10. sekund. Dvs 2 per sekund.
Dette opfyldes så rigeligt, endda under øget belastning med flere nodes og tråde.
Cpu status: cpu forbruget konstant over test perioden. Det svinger inden for et interval og rammer aldrig i nærheden af loftet.
io på netværk: for både LAR og CAVE er der er en jævn strøm af læs og skriv via netværket
Hukommelses forbrug: både LAR og CAVE håndterer brug af hukommelse fint
Garbage collection: både LAR og CAVE servicen kører jævnligt garbage collection og dermed stiger hukommelses forbruget ikke over tid. Dette er et tegn på, at vi ikke har memory leaks.

Derudover kan nævnes, at de 3 kald der gik galt under testen og returnerede http 500, fejlede pga. manglende svar fra en af de 3 MSB service kald: Service Unavailable.

1. Baggrundsbelastning
  1. Notifikation broker skal lave 40 adviseringer per sekund fordelt ligeligt på 20 udvalgte pullpoints
  2. Dvs. 2 adviseringer per pullpoint per sekund
2. Test: 1 kald til getMessage på hver af de 20 udvalgte pullpoints hver 10. sekund. Dvs. 2 kald per sekund
Krav:
1. Gennemsnitlig svartid skal være under 5.000 millisekunder
2. 95 % skal være under 10.000 millisekunder
3. 99 % skal være under 20.000 millisekunder