100 days of a monitoring server I built myself: what I did well and what needs fixing
I went back through the records of 270,000 checks. Checking the public domain was a good call. Self-monitoring, sequential checks, endless history and tokens in logs need fixing.
#Monitoring #Retrospective #Operations #Health check #Node.js
I first brought up the monitoring server on June 6, so it's been a little over 100 days. In that time I added a status page , down alerts and PM2 crash loop monitoring , one after another. I covered the features in the earlier posts, so this time I'm going back through the records that have piled up and sorting out what I did well and what needs fixing. The needs-fixing side is longer. The numbers from 100 days Monitored targets 10 (1:1 with PM2 apps and Apache vhosts) Total checks 271,360 (as of September 15) Failures 31 Avg response 25ms Responses over 5s 49 health_history 20.5MB What I did well: checking through the real domain I registered the health check targets not as internal ports like localhost:5000 but as real addresses like https://blog.jaeyonging.com . The monitoring server is on the same machine, so hitting the internal port would admittedly be faster and simpler. But visitors don't come in through the internal port. They look up DNS, Apache terminates TLS, and the proxy passes the request on to the app. Checking through the real address means checking that entire path along with it. This is what the status page looks like right now. There are two yellow cells in the middle of the blog's bar. One is August 14 and the other is August 18, which I'll get to right below. The August 18 records show that difference. 14:39:21 Blog getaddrinfo EAI_AGAIN blog.jaeyonging.com 14:39:21 Couples app API getaddrinfo EAI_AGAIN couple.jaeyonging.com 14:44:22 Blog getaddrinfo EAI_AGAIN blog.jaeyonging.com The apps were fine and it was the DNS lookup that failed. If I had checked through internal ports, this wouldn't have been recorded. A CPU 62.4% alert was logged in the same second, but I don't know whether the two are related, because the metrics from that day are gone. This comes up again below. What I did well: not bringing in a new tool I didn't use something like UptimeRobot or Grafana and built it on the same Express, MySQL and React structure as my other projects. There's no extra cost, and when I launch a new service, registering it on the port management screen creates the Apache vhost and the health check together. And the data is in my own DB. That's why I could count "how many emails would it have been if I'd alerted on every failure" straight from SQL in the previous post, and it's where all the numbers in this post come from too. Of course there's a price. I run into problems one at a time that a tool someone else built would already have solved. The list is below. Needs fixing 1: the monitoring server monitors itself On the status page, the uptime for the "Monitoring" item is 99.99%. But this number shouldn't be trusted. When the monitoring server dies, the health checks stop with it. While it's stopped, failures don't pile up. There are simply no records , and since uptime is the share of recorded checks that succeeded, the time it was dead doesn't enter the calculation. If the whole server goes down, it can't send the alert email either. It's a structure that gets quieter the bigger the outage is. According to PM2, monitor-server had restarted 8 times in total when I wrote this post, and 9 times now. That number includes the restarts I did myself on deploys, so they're probably not all outages, but with this structure there's no way to check how many gaps there were in between. The fix is to have something look once more from the outside. The monitoring server would send a periodic signal to an external heartbeat service like healthchecks.io, and when the signal stops, the alert comes from outside. I haven't done it yet. Needs fixing 2: checks run one at a time, in order The records from the early hours of August 14 have a strange shape. 02:04:04 Monitoring timeout (10009ms) 02:04:14 Couples app API timeout (10003ms) 02:04:24 Coin tracker timeout (10007ms) 02:04:54 Portfolio 19ms 02:05:04 Travel API timeout (10004ms) 02:05:14 Game timeout (10007ms) 02:06:04 taro timeout (10001ms) 02:07:04 Blog timeout (10003ms) 02:08:04 Couples app API timeout (10003ms) The failures are logged exactly 10 seconds apart . That's because the scheduler checks the endpoints one at a time with await inside a for loop. If one request hits the 10 second timeout, the next one waits that long before it starts. for (const ep of endpoints) { const res = await axios({ url: ep.url, timeout: 10000, validateStatus: null }); // ... record, decide on alerts } There are two problems. One is that the check times get pushed back, so the records become inaccurate. The other is overlap. The scheduler runs every 60 seconds with setInterval , but if all 10 targets time out, one round takes 100 seconds. The next round starts before the previous one has finished. Digging through the records, I found 3 cases where the same endpoint was checked twice within 50 seconds. Fixing it isn't hard. Send them at the same time, and if the previous round is still running, skip the next one. let running = false; async function runHealthChecks() { if (running) return; // if the previous round hasn't finished, skip this one running = true; try { const endpoints = await dueEndpoints(); await Promise.allSettled(endpoints.map(checkOne)); } finally { running = false; } } Needs fixing 3: when everything fails together, it isn't a service outage Looking at the same August 14 records again, 7 of the 8 targets registered at the time timed out within 4 minutes. Rather than seven apps having problems at that same moment, it's far more likely that something was wrong on a shared path like the server, the network or Apache. But on the status page it's logged as if seven services each had their own outage. On top of that, I don't know the cause. I wanted to look at the CPU and memory at that time, but metrics_history is only kept for 24 hours, so it was already deleted. The same goes for the August 18 DNS failure above. Two things are needed here. One is to group it and show it as a common outage instead of individual ones when several services fail together in the same time window, and the other is to keep the metrics from before and after an outage regardless of the retention period. Needs fixing 4: check history piles up without end health_history has no code that deletes anything. It grows by about 3,200 rows a day and is now 270,000 rows, 20.5MB. The size itself is still fine, but the status page only uses 90 days of it, and even then only looks at daily aggregates. This GROUP BY is also why the first request to /api/status takes 0.75 seconds when the cache is empty. At this rate it passes 1 million rows in a year. The method is already inside this project. For visit statistics, the daily aggregates are moved into the visit_stats table before the Apache logs get deleted by rotation. Health checks can do the same: store the number of checks and successes per day separately, and in the raw table keep only the failed rows for a long time and delete the successful rows after about 30 days. Needs fixing 5: the SSE token ends up in the Apache log The dashboard's live graphs come in over SSE. The browser's EventSource can't attach request headers, so I've been passing the JWT in the query string. GET /api/metrics/stream?token=eyJhbGciOi... The query string is part of the URL, so it's written to the Apache access log as is. I searched the logs thinking surely not, and in the September 9 log there was a line with the raw token in it . The token lives for 24 hours, so it's expired now, but it means that for those 24 hours anyone who could read the logs could have gotten into my dashboard. This dashboard has a web terminal too. There are a few options. Issue a one-time ticket that lasts a few dozen seconds just for the stream and pass that in the query, move the token to a cookie, or drop the query string from the Apache log format. The first one looks the cleanest. Needs fixing 6: the small stuff The "Open monitor dashboard" link in the down alert email points to /healthcheck . That path went away in August when I moved the admin screens under /dashboard , so clicking it now bounces you to the public status page. I wrote the email code after moving the paths and still put in the old one. The manual check button on the health check screen goes through different code from the scheduler. It records the result but doesn't touch the consecutive failure count or the alert state. It's the same check with two paths, so if I fix only one side the two drift apart. CORS is open with origin: '*' . Authentication uses the token in the header, so it's not something that gets broken into right away, but there's no reason to leave it open either. Addendum: I fixed three of them the next day The day after I published this post, I fixed the three most urgent items on the list above first. First, the token. SSE and the web terminal no longer carry the JWT in the URL. Right before connecting, they get a 30 second one-time ticket from POST /api/auth/stream-ticket and pass that instead. It's a random string that exists only in server memory and is deleted as soon as it's used once, so even if it ends up in a log it can't be used again. Connecting with ?token= like before now returns a 401. However, because the ticket is one-time, the browser's automatic SSE reconnect ends in a 401. So I changed the hook to get a new ticket and reconnect by itself when the connection drops. The automatic reconnect that was there for convenience turned out to get in the way once I tightened security. For the sequential checks, I used the code written above as is, sending them at the same time with Promise.allSettled and skipping when the previous round is still running. After restarting, I looked at the records and 6 services were logged in the same second. The email link only needed its path corrected to /dashboard/healthcheck . The external heartbeat, grouping simultaneous failures, the history retention policy, the manual check path and CORS are still as they were. What I'm left with Monitoring you build yourself takes on the blind spots of the person who built it. I only thought about the case where an app dies, and didn't think about the case where the monitoring itself dies or where everything dies together. As a feature list it looked fine, and it was only after laying the records out in time order that I saw the failures logged 10 seconds apart. Still, because I'd been storing the records in my own DB, I was able to look back like this. If you have monitoring you built yourself, I'd recommend laying out the failure records in time order and looking through them once a few months in.