From 39df4eea926f49452c0592ad6056ac2e27ef013f Mon Sep 17 00:00:00 2001 From: Aram Akhavan Date: Mon, 28 Mar 2022 14:28:50 -0700 Subject: [PATCH 1/6] Ssynchronize push monitor heartbeats to api calls Includes a 1s buffer time to allow the push url to be called before the monitor is checked --- package-lock.json | 44 ++++++++++++++++----------------- package.json | 4 +-- server/model/monitor.js | 47 ++++++++++++++++++++---------------- server/routers/api-router.js | 7 +++--- 4 files changed, 54 insertions(+), 48 deletions(-) diff --git a/package-lock.json b/package-lock.json index 9bc402c0f..4f35ad4f0 100644 --- a/package-lock.json +++ b/package-lock.json @@ -26,7 +26,7 @@ "check-password-strength": "^2.0.5", "command-exists": "~1.2.9", "compare-versions": "~3.6.0", - "dayjs": "~1.10.8", + "dayjs": "^1.11.0", "express": "~4.17.3", "express-basic-auth": "~1.2.1", "favico.js": "^0.3.10", @@ -49,7 +49,7 @@ "prom-client": "~13.2.0", "prometheus-api-metrics": "~3.2.1", "qrcode": "~1.5.0", - "redbean-node": "0.1.3", + "redbean-node": "0.1.4", "socket.io": "~4.4.1", "socket.io-client": "~4.4.1", "socks-proxy-agent": "^6.1.1", @@ -5658,9 +5658,9 @@ } }, "node_modules/dayjs": { - "version": "1.10.8", - "resolved": "https://registry.npmjs.org/dayjs/-/dayjs-1.10.8.tgz", - "integrity": "sha512-wbNwDfBHHur9UOzNUjeKUOJ0fCb0a52Wx0xInmQ7Y8FstyajiV1NmK1e00cxsr9YrE9r7yAChE0VvpuY5Rnlow==" + "version": "1.11.0", + "resolved": "https://registry.npmjs.org/dayjs/-/dayjs-1.11.0.tgz", + "integrity": "sha512-JLC809s6Y948/FuCZPm5IX8rRhQwOiyMb2TfVVQEixG7P8Lm/gt5S7yoQZmC8x1UehI9Pb7sksEt4xx14m+7Ug==" }, "node_modules/debug": { "version": "4.3.4", @@ -13939,15 +13939,15 @@ } }, "node_modules/redbean-node": { - "version": "0.1.3", - "resolved": "https://registry.npmjs.org/redbean-node/-/redbean-node-0.1.3.tgz", - "integrity": "sha512-itAouTnNK12QXy10DxScFRDv/R3Zt1sZw+tfUQCsBALxDDCNXVUdkNTgClouUwbTDG1YMQkeoD1Je9ujN7u3yg==", + "version": "0.1.4", + "resolved": "https://registry.npmjs.org/redbean-node/-/redbean-node-0.1.4.tgz", + "integrity": "sha512-c1U6wnTeWS0c44tn9hkJWzjGgckLNJ8sN1E2bxnnnQsULOfvEVFLf8dLMjqhyyMrZ1L1mp8UvV4OfhRtH/ZrgQ==", "dependencies": { - "@types/node": "^14.17.7", + "@types/node": "^14.18.12", "await-lock": "^2.1.0", - "dayjs": "^1.10.6", - "glob": "^7.1.7", - "knex": "^0.95.9", + "dayjs": "^1.11.0", + "glob": "^7.2.0", + "knex": "^0.95.15", "lodash": "^4.17.21" } }, @@ -20965,9 +20965,9 @@ "dev": true }, "dayjs": { - "version": "1.10.8", - "resolved": "https://registry.npmjs.org/dayjs/-/dayjs-1.10.8.tgz", - "integrity": "sha512-wbNwDfBHHur9UOzNUjeKUOJ0fCb0a52Wx0xInmQ7Y8FstyajiV1NmK1e00cxsr9YrE9r7yAChE0VvpuY5Rnlow==" + "version": "1.11.0", + "resolved": "https://registry.npmjs.org/dayjs/-/dayjs-1.11.0.tgz", + "integrity": "sha512-JLC809s6Y948/FuCZPm5IX8rRhQwOiyMb2TfVVQEixG7P8Lm/gt5S7yoQZmC8x1UehI9Pb7sksEt4xx14m+7Ug==" }, "debug": { "version": "4.3.4", @@ -27229,15 +27229,15 @@ } }, "redbean-node": { - "version": "0.1.3", - "resolved": "https://registry.npmjs.org/redbean-node/-/redbean-node-0.1.3.tgz", - "integrity": "sha512-itAouTnNK12QXy10DxScFRDv/R3Zt1sZw+tfUQCsBALxDDCNXVUdkNTgClouUwbTDG1YMQkeoD1Je9ujN7u3yg==", + "version": "0.1.4", + "resolved": "https://registry.npmjs.org/redbean-node/-/redbean-node-0.1.4.tgz", + "integrity": "sha512-c1U6wnTeWS0c44tn9hkJWzjGgckLNJ8sN1E2bxnnnQsULOfvEVFLf8dLMjqhyyMrZ1L1mp8UvV4OfhRtH/ZrgQ==", "requires": { - "@types/node": "^14.17.7", + "@types/node": "^14.18.12", "await-lock": "^2.1.0", - "dayjs": "^1.10.6", - "glob": "^7.1.7", - "knex": "^0.95.9", + "dayjs": "^1.11.0", + "glob": "^7.2.0", + "knex": "^0.95.15", "lodash": "^4.17.21" }, "dependencies": { diff --git a/package.json b/package.json index 8a8bd1ebd..3ca2e6f58 100644 --- a/package.json +++ b/package.json @@ -76,7 +76,7 @@ "check-password-strength": "^2.0.5", "command-exists": "~1.2.9", "compare-versions": "~3.6.0", - "dayjs": "~1.10.8", + "dayjs": "^1.11.0", "express": "~4.17.3", "express-basic-auth": "~1.2.1", "favico.js": "^0.3.10", @@ -99,7 +99,7 @@ "prom-client": "~13.2.0", "prometheus-api-metrics": "~3.2.1", "qrcode": "~1.5.0", - "redbean-node": "0.1.3", + "redbean-node": "0.1.4", "socket.io": "~4.4.1", "socket.io-client": "~4.4.1", "socks-proxy-agent": "^6.1.1", diff --git a/server/model/monitor.js b/server/model/monitor.js index 2abf4be3b..d1107a37f 100644 --- a/server/model/monitor.js +++ b/server/model/monitor.js @@ -173,7 +173,7 @@ class Monitor extends BeanModel { let bean = R.dispense("heartbeat"); bean.monitor_id = this.id; - bean.time = R.isoDateTime(dayjs.utc()); + bean.time = R.isoDateTimeMillis(dayjs.utc()); bean.status = DOWN; if (this.isUpsideDown()) { @@ -348,25 +348,30 @@ class Monitor extends BeanModel { bean.msg = dnsMessage; bean.status = UP; } else if (this.type === "push") { // Type: Push - const time = R.isoDateTime(dayjs.utc().subtract(this.interval, "second")); - - let heartbeatCount = await R.count("heartbeat", " monitor_id = ? AND time > ? ", [ - this.id, - time - ]); - - log.debug("monitor", "heartbeatCount" + heartbeatCount + " " + time); - - if (heartbeatCount <= 0) { - // Fix #922, since previous heartbeat could be inserted by api, it should get from database - previousBeat = await Monitor.getPreviousHeartbeat(this.id); - - throw new Error("No heartbeat in the time window"); - } else { - // No need to insert successful heartbeat for push type, so end here - retries = 0; - this.heartbeatInterval = setTimeout(beat, beatInterval * 1000); - return; + log.debug(`[${this.name}] Checking monitor at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); + const bufferTime = 1000; // 1s buffer to accommodate clock differences + // Fix #922, since previous heartbeat could be inserted by api, it should get from database + previousBeat = await Monitor.getPreviousHeartbeat(this.id); + //If the previous beat was nonexistent, down or pending we use the regular + // beatInterval/retryInterval in the setTimeout further below + if (previousBeat) { + const msSinceLastBeat = dayjs.utc().valueOf() - dayjs.utc(previousBeat.time).valueOf(); + log.debug(`[${this.name}] msSinceLastBeat = ${msSinceLastBeat}`); + if (previousBeat.status !== UP || msSinceLastBeat > beatInterval * 1000 + bufferTime) { + throw new Error("No heartbeat in the time window"); + } else { + let timeout = beatInterval * 1000 - msSinceLastBeat; + if (timeout < 0) { + timeout = bufferTime; + } else { + timeout += bufferTime; + } + // No need to insert successful heartbeat for push type, so end here + retries = 0; + log.debug(`[${this.name}] timeout = ${timeout}`); + this.heartbeatInterval = setTimeout(beat, timeout); + return; + } } } else if (this.type === "steam") { @@ -694,7 +699,7 @@ class Monitor extends BeanModel { } else { // Handle new monitor with only one beat, because the beat's duration = 0 - let status = parseInt(await R.getCell("SELECT `status` FROM heartbeat WHERE monitor_id = ?", [monitorID])); + let status = parseInt(await R.getCell("SELECT `status` FROM heartbeat WHERE monitor_id = ?", [ monitorID ])); if (status === UP) { uptime = 1; diff --git a/server/routers/api-router.js b/server/routers/api-router.js index 578655e20..fa594c4eb 100644 --- a/server/routers/api-router.js +++ b/server/routers/api-router.js @@ -55,7 +55,7 @@ router.get("/api/push/:pushToken", async (request, response) => { let duration = 0; let bean = R.dispense("heartbeat"); - bean.time = R.isoDateTime(dayjs.utc()); + bean.time = R.isoDateTimeMillis(dayjs.utc()); if (previousHeartbeat) { isFirstBeat = false; @@ -63,8 +63,9 @@ router.get("/api/push/:pushToken", async (request, response) => { duration = dayjs(bean.time).diff(dayjs(previousHeartbeat.time), "second"); } - log.debug("router", "PreviousStatus: " + previousStatus); - log.debug("router", "Current Status: " + status); + log.debug(`/api/push/ called at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); + log.debug("PreviousStatus: " + previousStatus); + log.debug("Current Status: " + status); bean.important = Monitor.isImportantBeat(isFirstBeat, previousStatus, status); bean.monitor_id = monitor.id; From bb7d67f717d6a8f0a541fb18e6bfa6bc7b281b09 Mon Sep 17 00:00:00 2001 From: Aram Akhavan Date: Fri, 6 May 2022 09:58:05 -0700 Subject: [PATCH 2/6] Apply suggestions from code review Co-authored-by: Adam Stachowicz --- server/model/monitor.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/server/model/monitor.js b/server/model/monitor.js index d1107a37f..1bde1cb71 100644 --- a/server/model/monitor.js +++ b/server/model/monitor.js @@ -350,9 +350,9 @@ class Monitor extends BeanModel { } else if (this.type === "push") { // Type: Push log.debug(`[${this.name}] Checking monitor at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); const bufferTime = 1000; // 1s buffer to accommodate clock differences - // Fix #922, since previous heartbeat could be inserted by api, it should get from database + // Fix #922, since previous heartbeat could be inserted by API, it should get from database previousBeat = await Monitor.getPreviousHeartbeat(this.id); - //If the previous beat was nonexistent, down or pending we use the regular + // If the previous beat was nonexistent, down or pending we use the regular // beatInterval/retryInterval in the setTimeout further below if (previousBeat) { const msSinceLastBeat = dayjs.utc().valueOf() - dayjs.utc(previousBeat.time).valueOf(); From cd3fbc80b44a11cc62ee1b4194d16ebd541745a5 Mon Sep 17 00:00:00 2001 From: Aram Akhavan Date: Fri, 6 May 2022 16:05:24 -0700 Subject: [PATCH 3/6] Add first parameter back to logging in api router --- server/routers/api-router.js | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/server/routers/api-router.js b/server/routers/api-router.js index fa594c4eb..75729f170 100644 --- a/server/routers/api-router.js +++ b/server/routers/api-router.js @@ -63,9 +63,9 @@ router.get("/api/push/:pushToken", async (request, response) => { duration = dayjs(bean.time).diff(dayjs(previousHeartbeat.time), "second"); } - log.debug(`/api/push/ called at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); - log.debug("PreviousStatus: " + previousStatus); - log.debug("Current Status: " + status); + log.debug("router", `/api/push/ called at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); + log.debug("router", "PreviousStatus: " + previousStatus); + log.debug("router", "Current Status: " + status); bean.important = Monitor.isImportantBeat(isFirstBeat, previousStatus, status); bean.monitor_id = monitor.id; From ab4edf20928763f415d28865f5e4754cf6546196 Mon Sep 17 00:00:00 2001 From: Aram Akhavan Date: Thu, 26 May 2022 21:45:56 -0700 Subject: [PATCH 4/6] Fix log.debug calls --- server/model/monitor.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/server/model/monitor.js b/server/model/monitor.js index 1bde1cb71..b5b20f54c 100644 --- a/server/model/monitor.js +++ b/server/model/monitor.js @@ -348,7 +348,7 @@ class Monitor extends BeanModel { bean.msg = dnsMessage; bean.status = UP; } else if (this.type === "push") { // Type: Push - log.debug(`[${this.name}] Checking monitor at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); + log.debug("monitor", `[${this.name}] Checking monitor at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); const bufferTime = 1000; // 1s buffer to accommodate clock differences // Fix #922, since previous heartbeat could be inserted by API, it should get from database previousBeat = await Monitor.getPreviousHeartbeat(this.id); @@ -368,7 +368,7 @@ class Monitor extends BeanModel { } // No need to insert successful heartbeat for push type, so end here retries = 0; - log.debug(`[${this.name}] timeout = ${timeout}`); + log.debug("monitor", `[${this.name}] timeout = ${timeout}`); this.heartbeatInterval = setTimeout(beat, timeout); return; } From 7f46223d684aa7d68a5d9270dd0e5f32d095e762 Mon Sep 17 00:00:00 2001 From: Louis Lam Date: Sat, 28 May 2022 23:22:44 +0800 Subject: [PATCH 5/6] Fix another log.debug call --- server/model/monitor.js | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/server/model/monitor.js b/server/model/monitor.js index 0d2e8e2eb..ee7b4f43b 100644 --- a/server/model/monitor.js +++ b/server/model/monitor.js @@ -374,7 +374,9 @@ class Monitor extends BeanModel { // beatInterval/retryInterval in the setTimeout further below if (previousBeat) { const msSinceLastBeat = dayjs.utc().valueOf() - dayjs.utc(previousBeat.time).valueOf(); - log.debug(`[${this.name}] msSinceLastBeat = ${msSinceLastBeat}`); + + log.debug("monitor", `[${this.name}] msSinceLastBeat = ${msSinceLastBeat}`); + if (previousBeat.status !== UP || msSinceLastBeat > beatInterval * 1000 + bufferTime) { throw new Error("No heartbeat in the time window"); } else { From ea10d89f51fbba6d15ec9f4e4794817de5d85bc8 Mon Sep 17 00:00:00 2001 From: Aram Akhavan Date: Sat, 28 May 2022 19:57:45 -0700 Subject: [PATCH 6/6] show correct down message for first tick --- server/model/monitor.js | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/server/model/monitor.js b/server/model/monitor.js index ee7b4f43b..643d34a6f 100644 --- a/server/model/monitor.js +++ b/server/model/monitor.js @@ -370,13 +370,13 @@ class Monitor extends BeanModel { log.debug("monitor", `[${this.name}] Checking monitor at ${dayjs().format("YYYY-MM-DD HH:mm:ss.SSS")}`); const bufferTime = 1000; // 1s buffer to accommodate clock differences - // If the previous beat was nonexistent, down or pending we use the regular - // beatInterval/retryInterval in the setTimeout further below if (previousBeat) { const msSinceLastBeat = dayjs.utc().valueOf() - dayjs.utc(previousBeat.time).valueOf(); log.debug("monitor", `[${this.name}] msSinceLastBeat = ${msSinceLastBeat}`); + // If the previous beat was down or pending we use the regular + // beatInterval/retryInterval in the setTimeout further below if (previousBeat.status !== UP || msSinceLastBeat > beatInterval * 1000 + bufferTime) { throw new Error("No heartbeat in the time window"); } else { @@ -392,6 +392,8 @@ class Monitor extends BeanModel { this.heartbeatInterval = setTimeout(beat, timeout); return; } + } else { + throw new Error("No heartbeat in the time window"); } } else if (this.type === "steam") {