Merge pull request #310 from FlowFuse/309-audit-log-crahses

Audit log crashes
FlowFuse · Aug 29, 2024 · 9350330 · 9350330
2 parents e0f3063 + 97c11ed
commit 9350330
Show file tree

Hide file tree

Showing 2 changed files with 60 additions and 2 deletions.
diff --git a/lib/launcher.js b/lib/launcher.js
@@ -5,6 +5,7 @@ const path = require('path')
 const { log, info, debug, warn, NRlog } = require('./logging/log')
 const { copyDir, hasProperty } = require('./utils')
 const { States } = require('./states')
+const { default: got } = require('got')
 
 const MIN_RESTART_TIME = 10000 // 10 seconds
 const MAX_RESTART_COUNT = 5
@@ -385,6 +386,31 @@ class Launcher {
         }
     }
 
+    async logAuditEvent (event, body) {
+        const data = {
+            timestamp: Date.now(),
+            event
+        }
+        if (body && typeof body === 'object') {
+            if (body.error) {
+                data.error = {
+                    code: body.error.code || 'unexpected_error',
+                    error: body.error.error || body.error.message || 'Unexpected error'
+                }
+            } else {
+                Object.assign(data, body)
+            }
+        }
+        return got.post(this.auditLogURL, {
+            json: data,
+            headers: {
+                authorization: 'Bearer ' + this.config.token
+            }
+        }).catch(_err => {
+            console.error('Failed to log audit event', _err, event)
+        })
+    }
+
     async start () {
         if (this.deferredStop) {
             await this.deferredStop
@@ -528,6 +554,7 @@ class Launcher {
                         info('Node-RED restart loop detected - stopping')
                         this.state = States.CRASHED
                         restart = false
+                        await this.logAuditEvent('crashed', { info: { code: 'loop_detected', info: 'Node-RED restart loop detected' } })
                         await this.agent?.checkIn()
                     }
                 }

diff --git a/test/unit/lib/launcher_spec.js b/test/unit/lib/launcher_spec.js
@@ -32,10 +32,16 @@ describe('Launcher', function () {
         await fs.mkdir(path.join(config.dir, 'project'))
 
         sinon.replace(childProcess, 'spawn', sinon.fake(() => {
+            const callbacks = {}
             return {
-                on: (event, cb) => {},
+                on: (event, cb) => {
+                    callbacks[event] = cb
+                },
                 stdout: { on: (event, cb) => {} },
-                stderr: { on: (event, cb) => {} }
+                stderr: { on: (event, cb) => {} },
+                kill: () => {
+                    callbacks.exit && callbacks.exit(0)
+                }
             }
         }))
     })
@@ -332,6 +338,31 @@ describe('Launcher', function () {
         runtimeSettings.logging.auditLogger.should.have.property('loggingURL', expectedURL)
         runtimeSettings.logging.auditLogger.should.have.property('token', configWithPlatformInfo.token)
     })
+    it('calls logAuditEvent when it crashes', async function () {
+        const launcher = newLauncher({ config }, null, 'projectId', setup.snapshot)
+        should(launcher).be.an.Object()
+        await launcher.writeFlow()
+        await launcher.writeCredentials()
+
+        // stub the call to the audit logger function `logAuditEvent (event, body)`
+        const logAuditEventStub = sinon.stub(launcher, 'logAuditEvent').resolves()
+
+        // stub installDependencies so we don't actually install anything when starting
+        sinon.stub(launcher, 'installDependencies').resolves()
+
+        // simulate 5 recent start times so that it detects a boot loop and halts the restart process and reports a crash
+        launcher.startTime.push(Date.now())
+        launcher.startTime.push(Date.now())
+        launcher.startTime.push(Date.now())
+        launcher.startTime.push(Date.now())
+        launcher.startTime.push(Date.now())
+
+        await launcher.start() // childProcess.spawn is faked in beforeEach
+        launcher.proc.kill()
+        logAuditEventStub.calledOnce.should.be.true()
+        logAuditEventStub.args[0][0].should.eql('crashed')
+        logAuditEventStub.args[0][1].should.be.an.Object()
+    })
 
     describe('Proxy Support', function () {
         afterEach(async function () {