Merge pull request #1015 from appsignal/heartbeats

Implement heartbeats for Node.js

Author: unflxw

.changesets/add-heartbeats-support.md

@@ -0,0 +1,55 @@
+---
+bump: "minor"
+type: "add"
+---
+
+_Heartbeats are currently only available to beta testers. If you are interested in trying it out, [send an email to [email protected]](mailto:[email protected]?subject=Heartbeat%20beta)!_
+
+---
+
+Add heartbeats support. You can send heartbeats directly from your code, to
+track the execution of certain processes:
+
+```javascript
+import { heartbeat } from "@appsignal/nodejs"
+
+function sendInvoices() {
+  // ... your code here ...
+  heartbeat("send_invoices")
+}
+```
+
+You can pass a function to `heartbeat`, to report to AppSignal both when the
+process starts, and when it finishes, allowing you to see the duration of the
+process:
+
+```javascript
+import { heartbeat } from "@appsignal/nodejs"
+
+function sendInvoices() {
+  heartbeat("send_invoices", () => {
+    // ... your code here ...
+  })
+}
+```
+
+If an exception is raised within the function, the finish event will not be
+reported to AppSignal, triggering a notification about the missing heartbeat.
+The exception will bubble outside of the heartbeat function.
+
+If the function passed to `heartbeat` returns a promise, the finish event will
+be reported to AppSignal if the promise resolves. This means that you can use
+heartbeats to track the duration of async functions:
+
+```javascript
+import { heartbeat } from "@appsignal/nodejs"
+
+async function sendInvoices() {
+  await heartbeat("send_invoices", async () => {
+    // ... your async code here ...
+  })
+}
+```
+
+If the promise is rejected, or if it never resolves, the finish event will
+not be reported to AppSignal.

.changesets/appsignal-stop-must-be-awaited.md

@@ -0,0 +1,25 @@
+---
+bump: "patch"
+type: "change"
+---
+
+`Appsignal.stop()` now returns a promise. For your application to wait until
+AppSignal has been gracefully stopped, this promise must be awaited:
+
+```javascript
+import { Appsignal } from "@appsignal/nodejs"
+
+await Appsignal.stop()
+process.exit(0)
+```
+
+In older Node.js versions where top-level await is not available, terminate
+the application when the promise is settled:
+
+```javascript
+import { Appsignal } from "@appsignal/nodejs"
+
+Appsignal.stop().finally(() => {
+  process.exit(0)
+})
+```

src/__tests__/client.test.ts

@@ -23,8 +23,8 @@ describe("Client", () => {
     client = new Client({ ...DEFAULT_OPTS })
   })
 
-  afterEach(() => {
-    client.stop()
+  afterEach(async () => {
+    await client.stop()
   })
 
   it("starts the client", () => {
@@ -33,18 +33,18 @@ describe("Client", () => {
     expect(startSpy).toHaveBeenCalled()
   })
 
-  it("stops the client", () => {
+  it("stops the client", async () => {
     const extensionStopSpy = jest.spyOn(Extension.prototype, "stop")
-    client.stop()
+    await client.stop()
     expect(extensionStopSpy).toHaveBeenCalled()
   })
 
-  it("stops the probes when the client is active", () => {
+  it("stops the probes when the client is active", async () => {
     client = new Client({ ...DEFAULT_OPTS, active: true })
     const probes = client.metrics().probes()
     expect(probes.isRunning).toEqual(true)
 
-    client.stop()
+    await client.stop()
     expect(probes.isRunning).toEqual(false)
   })
 

src/__tests__/heartbeat.test.ts

@@ -0,0 +1,274 @@
+import nock, { Scope } from "nock"
+import { heartbeat, Heartbeat, EventKind } from "../heartbeat"
+import { Client, Options } from "../client"
+
+const DEFAULT_CLIENT_CONFIG: Partial<Options> = {
+  active: true,
+  name: "Test App",
+  pushApiKey: "test-push-api-key",
+  environment: "test",
+  hostname: "test-hostname"
+}
+
+function mockHeartbeatRequest(
+  kind: EventKind,
+  { delay } = { delay: 0 }
+): Scope {
+  return nock("https://appsignal-endpoint.net:443")
+    .post("/heartbeats/json", body => {
+      return body.name === "test-heartbeat" && body.kind === kind
+    })
+    .query({
+      api_key: "test-push-api-key",
+      name: "Test App",
+      environment: "test",
+      hostname: "test-hostname"
+    })
+    .delay(delay)
+    .reply(200, "")
+}
+
+function nextTick(fn: () => void): Promise<void> {
+  return new Promise(resolve => {
+    process.nextTick(() => {
+      fn()
+      resolve()
+    })
+  })
+}
+
+function sleep(ms: number): Promise<void> {
+  return new Promise(resolve => {
+    setTimeout(resolve, ms)
+  })
+}
+
+function interceptRequestBody(scope: Scope): Promise<string> {
+  return new Promise(resolve => {
+    scope.on("request", (_req, _interceptor, body: string) => {
+      resolve(body)
+    })
+  })
+}
+
+describe("Heartbeat", () => {
+  let client: Client
+  let theHeartbeat: Heartbeat
+
+  beforeAll(() => {
+    theHeartbeat = new Heartbeat("test-heartbeat")
+
+    if (!nock.isActive()) {
+      nock.activate()
+    }
+  })
+
+  beforeEach(() => {
+    client = new Client(DEFAULT_CLIENT_CONFIG)
+
+    nock.cleanAll()
+    nock.disableNetConnect()
+  })
+
+  afterEach(() => {
+    client.stop()
+  })
+
+  afterAll(() => {
+    nock.restore()
+  })
+
+  it("does not transmit any events when AppSignal is not active", async () => {
+    client.stop()
+    client = new Client({
+      ...DEFAULT_CLIENT_CONFIG,
+      active: false
+    })
+
+    const startScope = mockHeartbeatRequest("start")
+    const finishScope = mockHeartbeatRequest("finish")
+
+    await expect(theHeartbeat.start()).resolves.toBeUndefined()
+    await expect(theHeartbeat.finish()).resolves.toBeUndefined()
+
+    expect(startScope.isDone()).toBe(false)
+    expect(finishScope.isDone()).toBe(false)
+  })
+
+  it("heartbeat.start() sends a heartbeat start event", async () => {
+    const scope = mockHeartbeatRequest("start")
+
+    await expect(theHeartbeat.start()).resolves.toBeUndefined()
+
+    scope.done()
+  })
+
+  it("heartbeat.finish() sends a heartbeat finish event", async () => {
+    const scope = mockHeartbeatRequest("finish")
+
+    await expect(theHeartbeat.finish()).resolves.toBeUndefined()
+
+    scope.done()
+  })
+
+  it("Heartbeat.shutdown() awaits pending heartbeat event promises", async () => {
+    const startScope = mockHeartbeatRequest("start", { delay: 100 })
+    const finishScope = mockHeartbeatRequest("finish", { delay: 200 })
+
+    let finishPromiseResolved = false
+    let shutdownPromiseResolved = false
+
+    const startPromise = theHeartbeat.start()
+
+    theHeartbeat.finish().then(() => {
+      finishPromiseResolved = true
+    })
+
+    const shutdownPromise = Heartbeat.shutdown().then(() => {
+      shutdownPromiseResolved = true
+    })
+
+    await expect(startPromise).resolves.toBeUndefined()
+
+    // The finish promise should still be pending, so the shutdown promise
+    // should not be resolved yet.
+    await nextTick(() => {
+      expect(finishPromiseResolved).toBe(false)
+      expect(shutdownPromiseResolved).toBe(false)
+    })
+
+    startScope.done()
+
+    // The shutdown promise should not resolve until the finish promise
+    // resolves.
+    await expect(shutdownPromise).resolves.toBeUndefined()
+
+    await nextTick(() => {
+      expect(finishPromiseResolved).toBe(true)
+    })
+
+    finishScope.done()
+  })
+
+  describe("Appsignal.heartbeat()", () => {
+    it("without a function, sends a heartbeat finish event", async () => {
+      const startScope = mockHeartbeatRequest("start")
+      const finishScope = mockHeartbeatRequest("finish")
+
+      expect(heartbeat("test-heartbeat")).toBeUndefined()
+
+      await nextTick(() => {
+        expect(startScope.isDone()).toBe(false)
+        finishScope.done()
+      })
+    })
+
+    describe("with a function", () => {
+      it("sends heartbeat start and finish events", async () => {
+        const startScope = mockHeartbeatRequest("start")
+        const startBody = interceptRequestBody(startScope)
+
+        const finishScope = mockHeartbeatRequest("finish")
+        const finishBody = interceptRequestBody(finishScope)
+
+        expect(
+          heartbeat("test-heartbeat", () => {
+            const thisSecond = Math.floor(Date.now() / 1000)
+
+            // Since this function must be synchronous, we need to deadlock
+            // until the next second in order to obtain different timestamps
+            // for the start and finish events.
+            // eslint-disable-next-line no-constant-condition
+            while (true) {
+              if (Math.floor(Date.now() / 1000) != thisSecond) break
+            }
+
+            return "output"
+          })
+        ).toBe("output")
+
+        // Since the function is synchronous and deadlocks, the start and
+        // finish events' requests are actually initiated simultaneously
+        // afterwards, when the function finishes and the event loop ticks.
+        await nextTick(() => {
+          startScope.done()
+          finishScope.done()
+        })
+
+        expect(JSON.parse(await finishBody).timestamp).toBeGreaterThan(
+          JSON.parse(await startBody).timestamp
+        )
+      })
+
+      it("does not send a finish event when the function throws an error", async () => {
+        const startScope = mockHeartbeatRequest("start")
+        const finishScope = mockHeartbeatRequest("finish")
+
+        expect(() => {
+          heartbeat("test-heartbeat", () => {
+            throw new Error("thrown")
+          })
+        }).toThrow("thrown")
+
+        await nextTick(() => {
+          startScope.done()
+          expect(finishScope.isDone()).toBe(false)
+        })
+      })
+    })
+
+    describe("with an async function", () => {
+      it("sends heartbeat start and finish events", async () => {
+        const startScope = mockHeartbeatRequest("start")
+        const startBody = interceptRequestBody(startScope)
+
+        const finishScope = mockHeartbeatRequest("finish")
+        const finishBody = interceptRequestBody(finishScope)
+
+        await expect(
+          heartbeat("test-heartbeat", async () => {
+            await nextTick(() => {
+              startScope.done()
+              expect(finishScope.isDone()).toBe(false)
+            })
+
+            const millisecondsToNextSecond = 1000 - (Date.now() % 1000)
+            await sleep(millisecondsToNextSecond)
+
+            return "output"
+          })
+        ).resolves.toBe("output")
+
+        await nextTick(() => {
+          startScope.done()
+          finishScope.done()
+        })
+
+        expect(JSON.parse(await finishBody).timestamp).toBeGreaterThan(
+          JSON.parse(await startBody).timestamp
+        )
+      })
+
+      it("does not send a finish event when the promise returned is rejected", async () => {
+        const startScope = mockHeartbeatRequest("start")
+        const finishScope = mockHeartbeatRequest("finish")
+
+        await expect(
+          heartbeat("test-heartbeat", async () => {
+            await nextTick(() => {
+              startScope.done()
+              expect(finishScope.isDone()).toBe(false)
+            })
+
+            throw new Error("rejected")
+          })
+        ).rejects.toThrow("rejected")
+
+        await nextTick(() => {
+          startScope.done()
+          expect(finishScope.isDone()).toBe(false)
+        })
+      })
+    })
+  })
+})