Merge pull request #27 from irvinlim/system-log-docker-lambda

Capture system logs from docker-lambda

Author: irvinlim

package-lock.json

@@ -23,11 +23,13 @@
         "dotenv": "^5.0.0",
         "fs-extra": "^5.0.0",
         "jest": "^22.0.0",
-        "rimraf": "^2.6.2"
+        "rimraf": "^2.6.2",
+        "strip-ansi": "^4.0.0"
     },
     "jest": {
         "testEnvironment": "node",
-        "testRegex": "\\.test\\.js$"
+        "testRegex": "\\.test\\.js$",
+        "noStackTrace": true
     },
     "scripts": {
         "build": "npm run build:init && npm run build:js && npm run build:install",

package.json

@@ -0,0 +1,70 @@
+import stripAnsi from 'strip-ansi';
+
+// Define which system logs to strip out when parsing stderr from docker-lambda.
+const BLACKLISTED_GREPS = [
+    /^START RequestId: /,
+    /^END RequestId: /,
+    /^REPORT RequestId: /,
+];
+
+// Define the spliterator for syslog headers.
+const SYSLOG_HEADER_GREP = /\n?\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z\t[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}\t/;
+
+/**
+ * Returns an array of lines that were logged using console.log()
+ * within an invocation of AWS Lambda, extracted from the system log.
+ *
+ * @param {string} stderr Raw log from AWS Lambda.
+ * @returns {array} Array of lines that were logged to the console.
+ */
+function getSysLogLines(stderr) {
+    return stderr
+        .trim()
+        .split('\n')
+        .map(stripAnsi)
+        .filter(line => BLACKLISTED_GREPS.every(grep => !grep.test(line)))
+        .join('\n')
+        .split(SYSLOG_HEADER_GREP)
+        .filter(x => x && x.length);
+}
+
+/**
+ * Formats a list of console.log() message to be displayed in
+ * the test runner.
+ *
+ * @param {string[]} messages Messages to be displayed.
+ * @returns {string} Formatted console messages.
+ */
+function formatLogForConsole(messages) {
+    const lines = [
+        '\u001b[1;33mCaptured logs while executing Lambda function:\u001b[0m',
+        ...messages,
+    ];
+
+    return lines.join('\n\n');
+}
+
+/**
+ * Formats an error message to be displayed in the test runner
+ * when the Lambda invocation encounters an error.
+ *
+ * @param {string} message Error message to be displayed.
+ * @param {string} stderr AWS system log redirected from stderr.
+ * @returns {string} Formatted error message.
+ */
+function formatLogForError(message, stderr) {
+    const lines = [
+        '\u001b[1;31mError while executing Lambda function:\u001b[0m',
+        message + '\n',
+        '\u001b[1;33mDisplaying AWS Lambda system log:\u001b[0m',
+        stripAnsi(stderr),
+    ];
+
+    return lines.join('\n');
+}
+
+module.exports = {
+    getSysLogLines,
+    formatLogForConsole,
+    formatLogForError,
+};

test/util/logs.js

@@ -1,3 +1,5 @@
+import { formatLogForConsole, formatLogForError, getSysLogLines } from './logs';
+
 import dockerLambda from 'docker-lambda';
 import dotenv from 'dotenv';
 import path from 'path';
@@ -6,35 +8,51 @@ import path from 'path';
 dotenv.config();
 
 function run(event) {
-    // Run the Lambda function.
-    let result;
-
-    try {
-        // Run the Lambda in Docker.
-        result = dockerLambda({
-            // Use the Node.js 6.10.0 image.
-            dockerImage: 'lambci/lambda:nodejs6.10',
-            // Bind the build directory as a volume to /var/task.
-            taskDir: path.join(__dirname, '../dist'),
-            // Pass an event to the Lambda function.
-            event,
-            // Pass AWS credentials from environment.
-            // NOTE: Jest needs the environment variable values explicitly,
-            // see https://github.com/facebook/jest/issues/5362.
-            dockerArgs: [
-                '-e',
-                `AWS_ACCESS_KEY_ID=${process.env.AWS_ACCESS_KEY_ID}`,
-                '-e',
-                `AWS_SECRET_ACCESS_KEY=${process.env.AWS_SECRET_ACCESS_KEY}`,
-            ],
-        });
-    } catch (err) {
+    // Run the Lambda in Docker.
+    const result = dockerLambda({
+        // Use the Node.js 6.10.0 image.
+        dockerImage: 'lambci/lambda:nodejs6.10',
+
+        // Bind the build directory as a volume to /var/task.
+        taskDir: path.join(__dirname, '../dist'),
+
+        // Capture both stderr and stdout, instead of catching Errors.
+        returnSpawnResult: true,
+
+        // Pass an event to the Lambda function.
+        event,
+
+        // Pass AWS credentials from environment.
+        // NOTE: Jest needs the environment variable values explicitly,
+        // see https://github.com/facebook/jest/issues/5362.
+        dockerArgs: [
+            '-e',
+            `AWS_ACCESS_KEY_ID=${process.env.AWS_ACCESS_KEY_ID}`,
+            '-e',
+            `AWS_SECRET_ACCESS_KEY=${process.env.AWS_SECRET_ACCESS_KEY}`,
+        ],
+    });
+
+    // Catch Lambda errors, based on spawn status codes/errors.
+    if (result.error || result.status !== 0) {
         // Throw errors back to test runner.
-        console.error('Error while executing Lambda function: ', err.message);
-        throw err;
+        const { errorMessage } = JSON.parse(result.stdout);
+
+        // Format error message to be displayed in test runner.
+        const combinedErrorMsg = formatLogForError(errorMessage, result.stderr);
+
+        throw new Error(combinedErrorMsg);
+    }
+
+    // Capture any console.log occurrences by inspecting the syslog.
+    const logs = getSysLogLines(result.stderr);
+
+    // Display all messages in a single block in the test runner.
+    if (logs.length) {
+        console.log(formatLogForConsole(logs));
     }
 
-    return result;
+    return JSON.parse(result.stdout);
 }
 
 module.exports = run;