It has now been about 24 hours since I started my quest to speed up my templating engine. It took about 1.3 seconds or 1300ms to generate my blog index page and after spending 86,400,000[Not really, I didn't spend the entire time chained to my desk, it just felt like it] (86 million 400 thousand) ms, I have cut it down to 75ms.
TLDR:
1300ms: Start
0900ms: Change the CONVERTs
0800ms: Skip EVALUATE on numbers
0750ms: Add ENV()
0450ms: Add FOR OF loops
0250ms: Add HASH.ITEM to POST directly
0240ms: Inline MAP.SET
0225ms: Cache the HASH calculation
0170ms: Cache the parsed tokens
0155ms: Cache the expression
0075ms: Cache access only expressions
I was working on my web server in BASIC and I wanted to start using it as the engine for my blog. I currently have some BASIC programs that chew through all my markdown files and it generates a blog out of it. I would like to get rid of this step and simply have my my web server do everything directly.
This meant that it would generate everything on the fly. The very first page I wired up was the blog index page and I immediately hit a wall. The page was taking about 1.5 seconds to load. This was on localhost. This was the moment that I knew I had to deal with the speed issue. The very first request and I knew that my template engine was taking too long.
I live posted[tooted, I know I know] on Mastodon as I tested and changed thinsg so it has an off the cuff feel as I was doing things. This post is largely a retelling.
The first thing I noticed about my blog rendering is that I had a MAP.GET call that was taking a relatively long time. After testing it, I realized that I was chaining 3 calls to the CONVERT command and that it was expensive. Changing this to a single CONVERT immediately gave me 400ms.
The second thing I did was skip the calls to my EVALUATE function if what it is trying to evaluate is a number. If it's a number, I don't need to pay the expense of making sure it is a number. This was a small optimization that got me 100ms.
I also inlined my MAP.GET function into my EVALUATE function. I was expecting this to give me a bit of a speedup as the test routine I wrote definitely saw a speed up. However my test routine was a simply for loop inside a call statement. Moving the for loop out of the subroutine sped things up but its possible that the stuff in MAP.GET is more expensive than the actual subroutine call itself.
The next optimization I implemented was adding an extra function called ENV. This way I could read variables directly in the template from the environment. I originally had a READ statement and then I would use that data. This got moved into the BASIC program, it would read things in and put them inside the ENV and then I would use a ENV.GET function inside the template. This cut the time by another 100ms.
At this point I was able to render my blog in 750ms.
I then added a whole new type of loops to my templating language. The FOR OF loop let me get rid of the use of the counter variable. This was 1 less access as access was definitely the bottleneck of my program. This cut down 300ms and brought my rendering of the blog index to 450ms.
The next step was to realize that I could embed the entire item I was using to pass data around in the FOR OF loop. Instead of calling the ENV.GET function to get things, I would have them directly accessible as part of the POST variable. This shaved off another 200ms.
Now that my rendering engine was at 250ms, this is when I got greedy and made it a goal to get under 150ms.
The first thing I did now was inline the MAP.SET function which shaved off 10ms.
At this point is when I started to abuse caching.
I cached the hash values of the last 10 things the MAP function saw and this sped things up. This brought the render time to 225ms.
I then cache the parsed tokens so that if the line has been cached before, I can skip the tokenizer and postfix to infix translation. I can have the parsed tokens go directly to the evaluation step. This sped the rendering to 170ms.
I then cache the expression itself so that I can skip most of the evaluation process as well. This now brings the render time to 155ms.
Finally, the last thing was to add a caching step in my renderer directly. So far all the work has been happening in my EVALUATION program and this is the first major work[I already re-wrote this previously] done in the renderer. I cache the expression and if the expression is an access only expression, I inline the access in the renderer rather than go to the evaluation step. This cut down the time by a whopping 80ms! My blog index can now be rendered in 75ms.
Now that is significantly faster than what I started with and I'm pretty happy with it. I immediately took a stab at the routine using my HTTP.SERVER and I am happy to report that my blog index now gets served at 90ms. There is a bit of overhead but I'm fine with that for now.
This was a fun and painful journey. I was lucky[I am quite privileged] enough to be able to spend a huge amount of time staring at my computer and trying and testing different things.My blog as of today is still not served from BASIC yet but it get's closer every day :)