Excerpt generator locks main process

[davidmerfield]

Around the middle of last night I received reports of intermittent 502 gateway errors. This indicates that the node.js application responsible for Blot was down (as opposed to the NGINX reverse proxy which sits between Blot and the internet).

I checked the logs and determined that Monit, the service used to check if Blot is responsive, was restarting the node.js application because its requests to Blot's health endpoints were timing out. I streamed the log file for Blot's sync process and ran this command to watch the response time for the sign-up page (which is not cached by NGINX and generated by the node.js server for each request):

watch -n1 "curl -o /dev/null -s -w '%{time_total}'  https://blot.im/sign-up"

It seemed Blot would sometimes take up to 30s to process a single request. Something was blocking the main process. I cross referenced the long response time with items in the sync queue and narrowed the suspects down to a particular HTML file, which I'll refer to as bug.html, containing a relatively large table (thousands of cells). Amusingly enough, the user was running a script which updated bug.html every 60 seconds. I emailed the customer to explain the issue and temporarily disabled the customer's blog.

I downloaded a copy of bug.html and messed around with it in my development environment. Here's the key output from the debug log:

...
  blot:models:entry:build:prepare /bug.html Generating makeSlug +0ms
  blot:models:entry:build:prepare /bug.html Generated  makeSlug +0ms
  blot:models:entry:build:prepare /bug.html Generating tags +0ms
  blot:models:entry:build:prepare /bug.html Generated  tags +1ms
  blot:models:entry:build:prepare /bug.html Generating  teasers +11s
  blot:models:entry:build:prepare /bug.html Generated  teasers +11s
  blot:models:entry:build:prepare /bug.html Generating decoding +0ms
  blot:models:entry:build:prepare /bug.html Generated  decoding +0ms
...

The function which generates the 'teaser' or excerpt for each blog post was taking 11s and locking the entire server in the process, since it's synchronous code.

---

My planned solution is to set up a queue to build blog posts across multiple processes, distinct from the main web sever. Then I will attack the specific bug in makeTeaser.

[davidmerfield]

Now build runs in its own process. Next I need to fix the specific issue in makeTeaser.

[davidmerfield]

I have deployed multiple build processes which convert files into blog posts, separate from the main process which handles requests. Now I just need to address the specific issue with the teaser generator and bug.html

[davidmerfield]

Moved to todo.txt in 74067aa