Fibonacci

De code die dit artikel inspireerde kan ik niet delen. In plaats daarvan nemen we een simpele Express server met een endpoint onder de loep die het n-de resultaat uit de fibonacci-reeks retourneert. De Fibonacci-reeks is een reeks getallen waar ieder getal de som is van de twee getallen ervoor. De eerste twee getallen zijn 0 en 1.

De code die we gebruiken voor onze test is een naïeve methode waarbij we recursief alle termen berekenen vanaf de beginwaarden 0 en 1. Het resultaat is dat voor relatief kleine waarden van n, het programma er minuten over doet om tot een antwoord te komen.

In de praktijk kunnen problemen met performance allerlei oorzaken hebben. Een naïeve implementatie van een algoritme is een zo’n oorzaak. In de code die tot inspiratie voor dit artikel leidde was het kopiëren van grote datastructuren de grootste boosdoener. Uiteindelijk zoeken we naar stukken code die langer duren dan we zouden verwachten en proberen hier alternatieven voor te vinden die een betere performance hebben.

// index.js
const { fibo } = require('./fibo.js');
const express = require('express');
const app = express();
const port = 3000;
app.get('/*', handleRequest);
app.listen(port, () => {
console.log(`Example app listening on port ${port}`);
});
function handleRequest(req, res) {
const url = req.url;
const split = url.split('/');
let result;
// Note: Unsafe: Length is unguarded
switch (split[1]) {
case 'fibo':
result = fibo(parseInt(split[2]));
break;
default:
result = 'Unknown url';
}
res.send(`${result}`);
}
// fibo.js
var exports = (module.exports = {});
exports.fibo = fibo;
function fibo(n) {
if (n === 0 || n === 1) {
return n;
}
return fibo(n-1) + fibo(n-2);
}

Chrome Dev Tools

De Chrome Dev Tools heeft een aparte versie waarin NodeJS-applicaties kunnen worden gedebugged. Deze heeft ook een profiler. Een profiler kijkt wanneer instructies worden uitgevoerd en aggregeert dit vervolgens in een handig overzicht. Om bij de devtools te komen open eerst de normale devtools. Start daarna de applicatie in debug mode met node –inspect index.js. Als je extern wil debuggen, dan moet je expliciet binden op localhost met node –inspect=0.0.0.0:9229 index.js .

Om effectief de profiler te gebruiken start je de profiler vlak voordat de code die je wil profilen, draait en stop je de profiler vlak erna. Dit kan bijvoorbeeld voor en na een API call, zoals we in dit voorbeeld gedaan hebben.

De profiler in Chrome Dev Tools toont automatisch de “Heavy (Bottom Up)”-tabel, gesorteerd op Self Time. Self Time is de tijd die wordt gespendeerd in de functie zelf, zonder de tijd in aangeroepen functies (figuur 1). Figuur 2 toont dit voor een aanroep van de fibonaccifunctie met een relatief lage waarde van n. In dit geval spenderen we 4,5 seconde in de functie fibo, maar bijna geen tijd in de functie handle die wordt aangeroepen iedere keer dat een API call wordt gedaan. Total Time is de tijd tussen het begin en het eind van een functie-aanroep inclusief aangeroepen functies binnen die functie. Voor geneste functie-aanroepen zoals bij onze fibonacci-functie kan deze tijd en het achterliggende percentage aardig oplopen, omdat we feitelijk heel veel executietijd dubbel tellen.

Zowel Self Time als Total Time zijn nuttig. Een hoge Self Time kan er op duiden dat een functie inefficiënt is of dat een efficiënte functie heel vaak wordt aangeroepen. Immers, een helper-functie die in 1ns wordt uitgevoerd, maar die 3 miljoen keer wordt aangeroepen heeft nog steeds een totale executietijd van 3 seconde. Een hoge Total Time kan tonen dat het lang duurt voordat een functie tot een antwoord komt, zelfs als het niet terugkomt in de Self Time van zichzelf of van individuele functies die die functie aanroept, dat die functie vaak wordt uitgevoerd of dat de functie vaak genest is in zichzelf.

De “Tree (Top Down)”-tabel (figuur 3) toont de call-stack van een applicatie, met de eerder genoemde Self Time en Total Time. De informatie die hieruit te halen valt is vaak visueel beter leesbaar via de “Chart” (figuur 4), welke horizontaal de tijd toont en verticaal de geneste functie aanroepen.

Informatie uit deze tool

Uit de tabel gesorteerd op Self Time kunnen we concluderen dat het programma de meeste tijd spendeert in de fibo-functie. Uit de code kunnen we halen dat deze functie heel simpel is. De executietijd komt niet overeen met onze verwachting. De Total Time, en een enkele blik op de Chart, geeft ons de informatie dat er heel veel nesting plaatsvindt.

Deze informatie zegt niets over hoe we dit probleem moeten oplossen. Het geeft ons wel een begin welke code we verder onder de loep moeten nemen. Een vraag die we bij dit stuk code moeten stellen bijvoorbeeld is of het daadwerkelijk noodzakelijk is om voor iedere aanroep van de fibo-functie het resultaat te berekenen van de twee voorgaande getallen uit de reeks.

Dev Tools in VS Code

VSCode komt standaard met een javascript debugger, maar op het moment van schrijven (maart 2022) zitten performance-gerelateerde tools alleen nog in de nightly build. Zoek op @id:ms-vscode.js-debug-nightly in de extensies-tab voor instructies hoe dit te installeren.

Met de optie “Debug: Take Performance Profile” kunnen we dezelfde tabellen en charts genereren als in de Chrome Dev Tools. Het voordeel ten opzichte van de Chrome Dev Tools is dat performance-informatie ook bij functies komt te staan in de code zelf (figuur 4), en dat we door kunnen klikken naar de definitie van de functie in VSCode. Hier kunnen we direct bewerken.

Debug package

In gevallen waar meerdere processen naast elkaar draaien, of waar we niet perse een CPU profile willen uitpluizen kan ook de lightweight debug package gebruikt worden. Deze package staat toe berichten te loggen, en houdt de verlopen tijd tussen twee berichten bij. Hiermee kan eenvoudig een tijdlijn gebouwd worden. Ook gebruikt dit package namespaces, waardoor workers bijvoorbeeld verschillende namen kunnen krijgen en zij onafhankelijk van elkaar kunnen worden getimed.

Daarnaast helpt een package als deze om in een testproject verschillende alternatieven te testen voor een geïdentificeerd performance probleem. Door de verschillende alternatieven na elkaar te testen en de timings tussen deze te vergelijken kan een beeld gevormd worden hoe de performance van alternatieven is.

In het volgende stuk code testen we bijvoorbeeld verschillende alternatieven voor een potentiele fix voor onze fibo-functie. We hebben geïdentificeerd dat de fibo-functie een zogenaamde pure functie is, en dat iedere aanroep met dezelfde parameters hetzelfde resultaat geeft. We willen weten wat de beste manier is om die waardes te cachen en terug te geen.

// analysis.js
const debug = require('debug')('analysis');
// We are figuring out if it is faster to cache the result of fibo(n) using an
// object or an array.
// We want the tests to be as similar as possible, so we will prepare the work they will do here
const numberOfTests = 500;
const maximumNumber = 100000;
const numberOfFunctionCalls = 1000000;
const arguments = [maximumNumber];
for (let i = 1; i < numberOfFunctionCalls; i++) {
arguments.push(Math.floor(Math.random() * maximumNumber));
}
// The first test uses an object
debug('---')
for (let i = 0; i < numberOfTests; i++) {
const test1CacheObject = {};
function test1(argument) {
if (test1CacheObject[argument] !== undefined) {
return test1CacheObject[argument];
}
const value = argument * 2.5;
test1CacheObject[argument] = value;
return value;
}
for (const argument of arguments) {
test1(argument);
}
}
debug('>>>> Test 1: object cache');
// The second test uses an array
debug('---')
for (let i = 0; i < numberOfTests; i++) {
const test2CacheObject = [];
function test2(argument) {
if (test2CacheObject[argument] !== undefined) {
return test2CacheObject[argument];
}
const value = argument * 2.5;
test2CacheObject[argument] = value;
return value;
}
for (const argument of arguments) {
test2(argument);
}
}
debug('>>>> Test 2: array cache');
// The third test uses an array with a fixed length
debug('---')
for (let i = 0; i < numberOfTests; i++) {
const test3CacheObject = new Array(maximumNumber);
function test3(argument) {
if (test3CacheObject[argument] !== undefined) {
return test3CacheObject[argument];
}
const value = argument * 2.5;
test3CacheObject[argument] = value;
return value;
}
for (const argument of arguments) {
test3(argument);
}
}
debug('>>>> Test 3: array cache with fixed length');

Het doel met deze code is om een representatieve situatie te hebben, zonder dat we heel veel tijd besteden om het daadwerkelijk in te bouwen. Na het uitvoeren van deze code (figuur 8) kunnen we concluderen dat in dit geval objecten iets sneller zijn dan arrays als we zo’n 100.000 resultaten willen cachen en verwachten zo’n 1.000.000 functieaanroepen te doen.

Resultaat

Een mogelijke verbetering van onze eerdere code is door de eerder genoemde caching in te bouwen. We krijgen dan iets in deze vorm.

// fibo.js
var exports = (module.exports = {});
exports.fibo = fibo;
var fiboCache = {};
function fibo(n) {
if (fiboCache[n]) {
return fiboCache[n];
}
if (n === 0 || n === 1) {
return n;
}
const result = fibo(n-1) + fibo(n-2);
fiboCache[n] = result;
return result;
}