From 1c48074b749343904f07abd53328a2233eccd47b Mon Sep 17 00:00:00 2001 From: liuyunn Date: Wed, 6 Mar 2024 14:17:13 -0800 Subject: [PATCH] feat: add execution id support (#592) When set LOG_EXECUTION_ID=True in environment variables or set --log-execution-id, execution id will be added to log along with trace and span id. Nodejs version 13.0.0 is required for this feature. --- README.md | 1 + docs/generated/api.json | 81 +++++++++++++++++ docs/generated/api.md | 3 + package-lock.json | 14 +-- package.json | 2 +- src/async_local_storage.ts | 49 ++++++++++ src/execution_context.ts | 37 ++++++++ src/functions.ts | 12 +++ src/logger.ts | 124 +++++++++++++++++++++++++ src/main.ts | 12 ++- src/options.ts | 29 ++++++ src/server.ts | 16 +++- src/testing.ts | 3 +- test/async_local_storage.ts | 37 ++++++++ test/execution_context.ts | 56 ++++++++++++ test/integration/legacy_event.ts | 22 +++-- test/logger.ts | 151 +++++++++++++++++++++++++++++++ test/options.ts | 71 ++++++++++++++- 18 files changed, 700 insertions(+), 20 deletions(-) create mode 100644 src/async_local_storage.ts create mode 100644 src/execution_context.ts create mode 100644 test/async_local_storage.ts create mode 100644 test/execution_context.ts create mode 100644 test/logger.ts diff --git a/README.md b/README.md index 14a25d8c..ac94300c 100644 --- a/README.md +++ b/README.md @@ -190,6 +190,7 @@ ignored. | `--target` | `FUNCTION_TARGET` | The name of the exported function to be invoked in response to requests. Default: `function` | | `--signature-type` | `FUNCTION_SIGNATURE_TYPE` | The signature used when writing your function. Controls unmarshalling rules and determines which arguments are used to invoke your function. Default: `http`; accepted values: `http` or `event` or `cloudevent` | | `--source` | `FUNCTION_SOURCE` | The path to the directory of your function. Default: `cwd` (the current working directory) | +| `--log-execution-id`| `LOG_EXECUTION_ID` | Enables execution IDs in logs, either `true` or `false`. When not specified, default to disable. Requires Node.js 13.0.0 or later. | You can set command-line flags in your `package.json` via the `start` script. For example: diff --git a/docs/generated/api.json b/docs/generated/api.json index e9bc6668..07d5e57f 100644 --- a/docs/generated/api.json +++ b/docs/generated/api.json @@ -1757,6 +1757,33 @@ "name": "Request_2", "preserveMemberOrder": false, "members": [ + { + "kind": "PropertySignature", + "canonicalReference": "@google-cloud/functions-framework!Request_2#executionId:member", + "docComment": "/**\n * Request-specified execution ID.\n */\n", + "excerptTokens": [ + { + "kind": "Content", + "text": "executionId?: " + }, + { + "kind": "Content", + "text": "string" + }, + { + "kind": "Content", + "text": ";" + } + ], + "isReadonly": false, + "isOptional": true, + "releaseTag": "Public", + "name": "executionId", + "propertyTypeTokenRange": { + "startIndex": 1, + "endIndex": 2 + } + }, { "kind": "PropertySignature", "canonicalReference": "@google-cloud/functions-framework!Request_2#rawBody:member", @@ -1784,6 +1811,60 @@ "startIndex": 1, "endIndex": 2 } + }, + { + "kind": "PropertySignature", + "canonicalReference": "@google-cloud/functions-framework!Request_2#spanId:member", + "docComment": "/**\n * Cloud Trace span ID.\n */\n", + "excerptTokens": [ + { + "kind": "Content", + "text": "spanId?: " + }, + { + "kind": "Content", + "text": "string" + }, + { + "kind": "Content", + "text": ";" + } + ], + "isReadonly": false, + "isOptional": true, + "releaseTag": "Public", + "name": "spanId", + "propertyTypeTokenRange": { + "startIndex": 1, + "endIndex": 2 + } + }, + { + "kind": "PropertySignature", + "canonicalReference": "@google-cloud/functions-framework!Request_2#traceId:member", + "docComment": "/**\n * Cloud Trace trace ID.\n */\n", + "excerptTokens": [ + { + "kind": "Content", + "text": "traceId?: " + }, + { + "kind": "Content", + "text": "string" + }, + { + "kind": "Content", + "text": ";" + } + ], + "isReadonly": false, + "isOptional": true, + "releaseTag": "Public", + "name": "traceId", + "propertyTypeTokenRange": { + "startIndex": 1, + "endIndex": 2 + } } ], "extendsTokenRanges": [ diff --git a/docs/generated/api.md b/docs/generated/api.md index 5868b4e9..56ea685d 100644 --- a/docs/generated/api.md +++ b/docs/generated/api.md @@ -112,7 +112,10 @@ export interface LegacyEvent { // @public (undocumented) interface Request_2 extends Request_3 { + executionId?: string; rawBody?: Buffer; + spanId?: string; + traceId?: string; } export { Request_2 as Request } diff --git a/package-lock.json b/package-lock.json index a2028d32..8c432c29 100644 --- a/package-lock.json +++ b/package-lock.json @@ -27,7 +27,7 @@ "@types/body-parser": "1.19.5", "@types/minimist": "1.2.5", "@types/mocha": "9.1.1", - "@types/node": "20.11.15", + "@types/node": "^20.11.24", "@types/on-finished": "2.3.4", "@types/semver": "^7.3.6", "@types/sinon": "^10.0.0", @@ -551,9 +551,9 @@ "dev": true }, "node_modules/@types/node": { - "version": "20.11.15", - "resolved": "https://registry.npmjs.org/@types/node/-/node-20.11.15.tgz", - "integrity": "sha512-gscmuADZfvNULx1eyirVbr3kVOVZtpQtzKMCZpeSZcN6MfbkRXAR4s9/gsQ4CzxLHw6EStDtKLNtSDL3vbq05A==", + "version": "20.11.24", + "resolved": "https://registry.npmjs.org/@types/node/-/node-20.11.24.tgz", + "integrity": "sha512-Kza43ewS3xoLgCEpQrsT+xRo/EJej1y0kVYGiLFE1NEODXGzTfwiC6tXTLMQskn1X4/Rjlh0MQUvx9W+L9long==", "dependencies": { "undici-types": "~5.26.4" } @@ -6535,9 +6535,9 @@ "dev": true }, "@types/node": { - "version": "20.11.15", - "resolved": "https://registry.npmjs.org/@types/node/-/node-20.11.15.tgz", - "integrity": "sha512-gscmuADZfvNULx1eyirVbr3kVOVZtpQtzKMCZpeSZcN6MfbkRXAR4s9/gsQ4CzxLHw6EStDtKLNtSDL3vbq05A==", + "version": "20.11.24", + "resolved": "https://registry.npmjs.org/@types/node/-/node-20.11.24.tgz", + "integrity": "sha512-Kza43ewS3xoLgCEpQrsT+xRo/EJej1y0kVYGiLFE1NEODXGzTfwiC6tXTLMQskn1X4/Rjlh0MQUvx9W+L9long==", "requires": { "undici-types": "~5.26.4" } diff --git a/package.json b/package.json index fe948b06..3d7d84f5 100644 --- a/package.json +++ b/package.json @@ -56,7 +56,7 @@ "@types/body-parser": "1.19.5", "@types/minimist": "1.2.5", "@types/mocha": "9.1.1", - "@types/node": "20.11.15", + "@types/node": "^20.11.24", "@types/on-finished": "2.3.4", "@types/semver": "^7.3.6", "@types/sinon": "^10.0.0", diff --git a/src/async_local_storage.ts b/src/async_local_storage.ts new file mode 100644 index 00000000..25cd64db --- /dev/null +++ b/src/async_local_storage.ts @@ -0,0 +1,49 @@ +import * as semver from 'semver'; +import {Request, Response} from './functions'; +import {NextFunction} from 'express'; +import {requiredNodeJsVersionForLogExecutionID} from './options'; +import type {AsyncLocalStorage} from 'node:async_hooks'; + +export interface ExecutionContext { + executionId?: string; + traceId?: string; + spanId?: string; +} + +let asyncLocalStorage: AsyncLocalStorage | undefined; + +export async function asyncLocalStorageMiddleware( + req: Request, + res: Response, + next: NextFunction +) { + if ( + semver.lt(process.versions.node, requiredNodeJsVersionForLogExecutionID) + ) { + // Skip for unsupported Node.js version. + next(); + return; + } + if (!asyncLocalStorage) { + const asyncHooks = await import('node:async_hooks'); + asyncLocalStorage = new asyncHooks.AsyncLocalStorage(); + } + + asyncLocalStorage.run( + { + executionId: req.executionId, + traceId: req.traceId, + spanId: req.spanId, + }, + () => { + next(); + } + ); +} + +export function getCurrentContext(): ExecutionContext | undefined { + if (!asyncLocalStorage) { + return undefined; + } + return asyncLocalStorage.getStore(); +} diff --git a/src/execution_context.ts b/src/execution_context.ts new file mode 100644 index 00000000..dcb199a3 --- /dev/null +++ b/src/execution_context.ts @@ -0,0 +1,37 @@ +import {Request, Response} from './functions'; +import {NextFunction} from 'express'; + +const FUNCTION_EXECUTION_ID_HEADER_KEY = 'function-execution-id'; +const TRACE_CONTEXT_HEADER_KEY = 'X-Cloud-Trace-Context'; + +const TRACE_CONTEXT_PATTERN = + /^(?\w+)\/(?\d+);o=(?.+)$/; + +function generateExecutionId() { + const timestampPart = Date.now().toString(36).slice(-6); + const randomPart = Math.random().toString(36).slice(-6); + return timestampPart + randomPart; +} + +export const executionContextMiddleware = ( + req: Request, + res: Response, + next: NextFunction +) => { + let executionId = req.header(FUNCTION_EXECUTION_ID_HEADER_KEY); + if (!executionId) { + executionId = generateExecutionId(); + } + req.executionId = executionId; + + const cloudTraceContext = req.header(TRACE_CONTEXT_HEADER_KEY); + if (cloudTraceContext) { + const match = cloudTraceContext.match(TRACE_CONTEXT_PATTERN); + if (match?.groups) { + const {traceId, spanId} = match.groups; + req.traceId = traceId; + req.spanId = spanId; + } + } + next(); +}; diff --git a/src/functions.ts b/src/functions.ts index ae7a908c..cd37b8f4 100644 --- a/src/functions.ts +++ b/src/functions.ts @@ -32,6 +32,18 @@ export interface Request extends ExpressRequest { * A buffer which provides access to the request's raw HTTP body. */ rawBody?: Buffer; + /** + * Request-specified execution ID. + */ + executionId?: string; + /** + * Cloud Trace trace ID. + */ + traceId?: string; + /** + * Cloud Trace span ID. + */ + spanId?: string; } /** diff --git a/src/logger.ts b/src/logger.ts index 8b824736..6b2ee2e4 100644 --- a/src/logger.ts +++ b/src/logger.ts @@ -14,6 +14,13 @@ import * as express from 'express'; import {FUNCTION_STATUS_HEADER_FIELD} from './types'; +import {getCurrentContext, ExecutionContext} from './async_local_storage'; +import {Buffer} from 'buffer'; + +export const EXECUTION_CONTEXT_LABELS_KEY = 'logging.googleapis.com/labels'; +export const EXECUTION_CONTEXT_TRACE_KEY = 'logging.googleapis.com/trace'; +export const EXECUTION_CONTEXT_SPAN_ID_KEY = 'logging.googleapis.com/spanId'; +const SEVERITY = 'severity'; /** * Logs an error message and sends back an error response to the incoming @@ -60,3 +67,120 @@ export function sendCrashResponse({ callback(); } } + +export function loggingHandlerAddExecutionContext() { + interceptStdoutWrite(); + interceptStderrWrite(); +} + +function interceptStdoutWrite() { + const originalStdoutWrite = process.stdout.write; + process.stdout.write = (data, ...args) => { + const {encoding, cb} = splitArgs(args); + const modifiedData = getModifiedData(data, encoding); + return originalStdoutWrite.apply(process.stdout, [modifiedData, cb]); + }; +} + +function interceptStderrWrite() { + const originalStderrWrite = process.stderr.write; + process.stderr.write = (data, ...args) => { + const {encoding, cb} = splitArgs(args); + const modifiedData = getModifiedData(data, encoding, true); + return originalStderrWrite.apply(process.stderr, [modifiedData, cb]); + }; +} + +export const errorHandler = ( + err: Error | any, + req: express.Request, + res: express.Response, + next: express.NextFunction +) => { + interceptStderrWrite(); + res.status(500); + res.render('error', {error: err}); +}; + +export function splitArgs(args: any[]) { + let encoding, cb; + if ( + args.length > 0 && + (Buffer.isEncoding(args[0]) || typeof args[0] === 'undefined') + ) { + encoding = args[0]; + args.shift(); + } + if (args.length > 0 && typeof args[0] === 'function') { + cb = args[0]; + } + return {encoding: encoding, cb: cb}; +} + +export function getModifiedData( + data: Uint8Array | string, + encoding?: BufferEncoding, + stderr = false +) { + const currentContext = getCurrentContext(); + if (!currentContext) { + return data; + } + const {isJSON, processedData} = processData(data, encoding); + let dataWithContext; + if (isJSON) { + dataWithContext = getJSONWithContext(processedData, currentContext); + } else { + dataWithContext = getTextWithContext(processedData, currentContext); + } + if (stderr) { + dataWithContext[SEVERITY] = 'ERROR'; + } + + return JSON.stringify(dataWithContext) + '\n'; +} + +function getTextWithContext( + data: Uint8Array | string, + context: ExecutionContext +) { + return { + message: data, + [EXECUTION_CONTEXT_LABELS_KEY]: {execution_id: context.executionId}, + [EXECUTION_CONTEXT_TRACE_KEY]: context.traceId, + [EXECUTION_CONTEXT_SPAN_ID_KEY]: context.spanId, + }; +} + +function getJSONWithContext(json: any, context: ExecutionContext) { + if (EXECUTION_CONTEXT_LABELS_KEY in json) { + json[EXECUTION_CONTEXT_LABELS_KEY]['execution_id'] = context.executionId; + } else { + json[EXECUTION_CONTEXT_LABELS_KEY] = {execution_id: context.executionId}; + } + return { + ...json, + [EXECUTION_CONTEXT_TRACE_KEY]: context.traceId, + [EXECUTION_CONTEXT_SPAN_ID_KEY]: context.spanId, + }; +} + +function processData(data: Uint8Array | string, encoding?: BufferEncoding) { + let decodedData; + try { + if (data instanceof Uint8Array) { + decodedData = Buffer.from(data.buffer).toString(); + } else { + decodedData = Buffer.from(data, encoding).toString(); + } + } catch (e) { + // Failed to decode, treat it as simple text. + return {isJSON: false, processedData: data}; + } + + try { + return {isJSON: true, processedData: JSON.parse(decodedData)}; + } catch (e) { + return {isJSON: false, processedData: decodedData}; + } +} diff --git a/src/main.ts b/src/main.ts index 4aaaba1c..3dd98398 100644 --- a/src/main.ts +++ b/src/main.ts @@ -20,6 +20,7 @@ import {getUserFunction} from './loader'; import {ErrorHandler} from './invoker'; import {getServer} from './server'; import {parseOptions, helpText, OptionsError} from './options'; +import {loggingHandlerAddExecutionContext} from './logger'; /** * Main entrypoint for the functions framework that loads the user's function @@ -33,6 +34,11 @@ export const main = async () => { console.error(helpText); return; } + + if (options.enableExecutionId) { + loggingHandlerAddExecutionContext(); + } + const loadedFunction = await getUserFunction( options.sourceLocation, options.target, @@ -44,7 +50,11 @@ export const main = async () => { process.exit(1); } const {userFunction, signatureType} = loadedFunction; - const server = getServer(userFunction!, signatureType); + const server = getServer( + userFunction!, + signatureType, + options.enableExecutionId + ); const errorHandler = new ErrorHandler(server); server .listen(options.port, () => { diff --git a/src/options.ts b/src/options.ts index 63d0d762..d761b86f 100644 --- a/src/options.ts +++ b/src/options.ts @@ -13,6 +13,7 @@ // limitations under the License. import * as minimist from 'minimist'; +import * as semver from 'semver'; import {resolve} from 'path'; import {SignatureType, isValidSignatureType} from './types'; @@ -47,6 +48,10 @@ export interface FrameworkOptions { * Whether or not the --help CLI flag was provided. */ printHelp: boolean; + /** + * Whether or not to enable execution id support. + */ + enableExecutionId: boolean; } /** @@ -108,6 +113,29 @@ const SignatureOption = new ConfigurableOption( } ); +export const requiredNodeJsVersionForLogExecutionID = '13.0.0'; +const ExecutionIdOption = new ConfigurableOption( + 'log-execution-id', + 'LOG_EXECUTION_ID', + false, + x => { + const nodeVersion = process.versions.node; + const isVersionSatisfied = semver.gte( + nodeVersion, + requiredNodeJsVersionForLogExecutionID + ); + const isTrue = + (typeof x === 'boolean' && x) || + (typeof x === 'string' && x.toLowerCase() === 'true'); + if (isTrue && !isVersionSatisfied) { + throw new OptionsError( + `Execution id is only supported with Node.js versions ${requiredNodeJsVersionForLogExecutionID} and above. Your current version is ${nodeVersion}. Please upgrade.` + ); + } + return isTrue; + } +); + export const helpText = `Example usage: functions-framework --target=helloWorld --port=8080 Documentation: @@ -138,5 +166,6 @@ export const parseOptions = ( sourceLocation: SourceLocationOption.parse(argv, envVars), signatureType: SignatureOption.parse(argv, envVars), printHelp: cliArgs[2] === '-h' || cliArgs[2] === '--help', + enableExecutionId: ExecutionIdOption.parse(argv, envVars), }; }; diff --git a/src/server.ts b/src/server.ts index ec3cff91..e4080d5c 100644 --- a/src/server.ts +++ b/src/server.ts @@ -23,6 +23,9 @@ import {legacyPubSubEventMiddleware} from './pubsub_middleware'; import {cloudEventToBackgroundEventMiddleware} from './middleware/cloud_event_to_background_event'; import {backgroundEventToCloudEventMiddleware} from './middleware/background_event_to_cloud_event'; import {wrapUserFunction} from './function_wrappers'; +import {asyncLocalStorageMiddleware} from './async_local_storage'; +import {executionContextMiddleware} from './execution_context'; +import {errorHandler} from './logger'; /** * Creates and configures an Express application and returns an HTTP server @@ -33,7 +36,8 @@ import {wrapUserFunction} from './function_wrappers'; */ export function getServer( userFunction: HandlerFunction, - functionSignatureType: SignatureType + functionSignatureType: SignatureType, + enableExecutionId: boolean ): http.Server { // App to use for function executions. const app = express(); @@ -110,6 +114,11 @@ export function getServer( // Disable Express eTag response header app.set('etag', false); + // Get execution context. + app.use(executionContextMiddleware); + // Store execution context to async local storge. + app.use(asyncLocalStorageMiddleware); + if ( functionSignatureType === 'event' || functionSignatureType === 'cloudevent' @@ -150,5 +159,10 @@ export function getServer( app.post('/*', requestHandler); } + // Error Handler + if (enableExecutionId) { + app.use(errorHandler); + } + return http.createServer(app); } diff --git a/src/testing.ts b/src/testing.ts index 4357e68f..f66baad7 100644 --- a/src/testing.ts +++ b/src/testing.ts @@ -50,6 +50,7 @@ export const getTestServer = (functionName: string): Server => { } return getServer( registeredFunction.userFunction, - registeredFunction.signatureType + registeredFunction.signatureType, + /*enableExecutionId=*/ false ); }; diff --git a/test/async_local_storage.ts b/test/async_local_storage.ts new file mode 100644 index 00000000..2145bd19 --- /dev/null +++ b/test/async_local_storage.ts @@ -0,0 +1,37 @@ +import { + asyncLocalStorageMiddleware, + getCurrentContext, + ExecutionContext, +} from '../src/async_local_storage'; +import {Request, Response} from '../src/functions'; +import {NextFunction} from 'express'; +import * as assert from 'assert'; + +describe('asyncLocalStorageMiddleware', () => { + it('async local storage', () => { + const req = { + body: 'test body', + executionId: 'testExecutionId', + traceId: 'testtrace', + spanId: 'testSpanId', + }; + let executionContext; + const next = () => { + // The store is accessible to operations created within the callback of run(). + executionContext = getCurrentContext() as ExecutionContext; + assert(executionContext); + assert.strictEqual(executionContext.executionId, req.executionId); + assert.strictEqual(executionContext.spanId, req.spanId); + assert.strictEqual(executionContext.traceId, req.traceId); + }; + + asyncLocalStorageMiddleware( + req as Request, + {} as Response, + next as NextFunction + ); + + // The store is not accessible outside of the run()'s callback function. + assert.strictEqual(getCurrentContext(), undefined); + }); +}); diff --git a/test/execution_context.ts b/test/execution_context.ts new file mode 100644 index 00000000..f92f01ab --- /dev/null +++ b/test/execution_context.ts @@ -0,0 +1,56 @@ +import {executionContextMiddleware} from '../src/execution_context'; +import {Request, Response} from '../src/functions'; +import * as assert from 'assert'; +import * as sinon from 'sinon'; + +describe('executionContextMiddleware', () => { + const createRequest = ( + body: object | string, + headers?: {[key: string]: string} + ) => + ({ + body, + header: (h: string) => { + return headers === undefined ? '' : headers[h]; + }, + }) as Request; + + const next = sinon.spy(); + const testSpanId = '123'; + const testTrace = 'testtrace'; + const validExecutionId = 'xn1h9xdgv6zw'; + const headers = { + 'X-Cloud-Trace-Context': `${testTrace}/${testSpanId};o=1`, + 'function-execution-id': validExecutionId, + }; + + it('uses execution ID in header', () => { + const req = createRequest({}, headers); + + executionContextMiddleware(req as Request, {} as Response, next); + + assert.strictEqual(req.executionId, validExecutionId); + assert.strictEqual(req.spanId, testSpanId); + assert.strictEqual(req.traceId, testTrace); + }); + + it('generates execution ID if not in header', () => { + const req = createRequest({}, headers); + + executionContextMiddleware(req as Request, {} as Response, next); + + assert(req.executionId); + assert.strictEqual(req.spanId, testSpanId); + assert.strictEqual(req.traceId, testTrace); + }); + + it('req trace undefined if not in header', () => { + const req = createRequest({}, {}); + + executionContextMiddleware(req as Request, {} as Response, next); + + assert(req.executionId); + assert.strictEqual(req.spanId, undefined); + assert.strictEqual(req.traceId, undefined); + }); +}); diff --git a/test/integration/legacy_event.ts b/test/integration/legacy_event.ts index 89d3f3d3..3213acd9 100644 --- a/test/integration/legacy_event.ts +++ b/test/integration/legacy_event.ts @@ -181,10 +181,14 @@ describe('Event Function', () => { it(test.name, async () => { let receivedData: {} | null = null; let receivedContext: functions.CloudFunctionsContext | null = null; - const server = getServer((data: {}, context: functions.Context) => { - receivedData = data; - receivedContext = context as functions.CloudFunctionsContext; - }, 'event'); + const server = getServer( + (data: {}, context: functions.Context) => { + receivedData = data; + receivedContext = context as functions.CloudFunctionsContext; + }, + 'event', + /*enableExecutionId=*/ false + ); const requestHeaders = { 'Content-Type': 'application/json', ...test.headers, @@ -200,9 +204,13 @@ describe('Event Function', () => { }); it('returns a 500 if the function throws an exception', async () => { - const server = getServer(() => { - throw 'I crashed'; - }, 'event'); + const server = getServer( + () => { + throw 'I crashed'; + }, + 'event', + /*enableExecutionId=*/ false + ); await supertest(server) .post('/') .send({ diff --git a/test/logger.ts b/test/logger.ts new file mode 100644 index 00000000..732598b4 --- /dev/null +++ b/test/logger.ts @@ -0,0 +1,151 @@ +import * as sinon from 'sinon'; +import * as assert from 'assert'; +import {splitArgs, getModifiedData} from '../src/logger'; +import * as executionContext from '../src/async_local_storage'; + +describe('splitArgs', () => { + const expectedCallback = () => {}; + const expectedEncoding = 'utf-8'; + + it('empty', () => { + const {encoding, cb} = splitArgs([]); + assert.equal(encoding, undefined); + assert.equal(cb, undefined); + }); + + it('callback', () => { + const {encoding, cb} = splitArgs([expectedCallback]); + assert.equal(encoding, undefined); + assert.equal(cb, expectedCallback); + }); + + it('encoding', () => { + const {encoding, cb} = splitArgs([expectedEncoding]); + assert.equal(encoding, expectedEncoding); + assert.equal(cb, undefined); + }); + + it('encoding and callback', () => { + const {encoding, cb} = splitArgs([expectedEncoding, expectedCallback]); + assert.equal(encoding, expectedEncoding); + assert.equal(cb, expectedCallback); + }); + + it('invalid args', () => { + const {encoding, cb} = splitArgs(['error-encoding', expectedCallback]); + assert.equal(encoding, undefined); + assert.equal(cb, undefined); + }); +}); + +describe('getModifiedData', () => { + const sampleText = 'abc'; + const sampleJSON = JSON.stringify({ + text: 'default text.', + component: 'arbitrary-property', + }); + const sampleUint8Arr = new Uint8Array(Buffer.from(sampleText)); + const expectedExecutionContext = { + executionId: 'testExecutionId', + traceId: 'testTraceId', + spanId: 'testSpanId', + }; + const expectedMetadata = { + 'logging.googleapis.com/labels': { + execution_id: 'testExecutionId', + }, + 'logging.googleapis.com/trace': 'testTraceId', + 'logging.googleapis.com/spanId': 'testSpanId', + }; + const expectedTextOutput = + JSON.stringify(Object.assign({message: sampleText}, expectedMetadata)) + + '\n'; + const expectedJSONOutput = + JSON.stringify(Object.assign(JSON.parse(sampleJSON), expectedMetadata)) + + '\n'; + + function utf8ToHex(data: string) { + return Buffer.from(data, 'utf-8').toString('hex'); + } + + let getCurrentContextStub: sinon.SinonStub; + beforeEach(() => { + getCurrentContextStub = sinon.stub(executionContext, 'getCurrentContext'); + getCurrentContextStub.returns(expectedExecutionContext); + }); + + afterEach(() => { + getCurrentContextStub.restore(); + }); + + it('simple text', () => { + const modifiedData = getModifiedData(sampleText); + assert.equal(modifiedData, expectedTextOutput); + }); + + it('json', () => { + const modifiedData = getModifiedData(sampleJSON); + assert.equal(modifiedData, expectedJSONOutput); + }); + + it('json with user label', () => { + const data = JSON.stringify({ + text: 'default text.', + component: 'arbitrary-property', + 'logging.googleapis.com/labels': {user_label_1: 'value_1'}, + }); + const expectedOutput = + JSON.stringify({ + text: 'default text.', + component: 'arbitrary-property', + 'logging.googleapis.com/labels': { + user_label_1: 'value_1', + execution_id: 'testExecutionId', + }, + 'logging.googleapis.com/trace': 'testTraceId', + 'logging.googleapis.com/spanId': 'testSpanId', + }) + '\n'; + const modifiedData = getModifiedData(data); + assert.equal(modifiedData, expectedOutput); + }); + + it('uint8array', () => { + const modifiedData = getModifiedData(sampleUint8Arr); + assert.equal(modifiedData, expectedTextOutput); + }); + + it('simple text with encoding', () => { + const modifiedData = getModifiedData(utf8ToHex(sampleText), 'hex'); + assert.equal(modifiedData, expectedTextOutput); + }); + + it('json with encoding', () => { + const modifiedData = getModifiedData(utf8ToHex(sampleJSON), 'hex'); + assert.equal(modifiedData, expectedJSONOutput); + }); + + it('uint8Array with encoding', () => { + // Encoding will be ignored when the first parameter is Uint8Array. + // This behavious is the same as process.stdout[/stderr].write. + const modifiedData = getModifiedData(sampleUint8Arr, 'hex'); + assert.equal(modifiedData, expectedTextOutput); + }); + + it('simple text with error', () => { + const modifiedData = getModifiedData(sampleText, undefined, true); + const expectedOutput = + JSON.stringify( + Object.assign(JSON.parse(expectedTextOutput), {severity: 'ERROR'}) + ) + '\n'; + assert.equal(modifiedData, expectedOutput); + }); + + it('json with error', () => { + const modifiedData = getModifiedData(sampleJSON, undefined, true); + const expectedOutput = + JSON.stringify( + Object.assign(JSON.parse(expectedJSONOutput), {severity: 'ERROR'}) + ) + '\n'; + assert.equal(modifiedData, expectedOutput); + }); +}); diff --git a/test/options.ts b/test/options.ts index d0a1a887..e928a0e4 100644 --- a/test/options.ts +++ b/test/options.ts @@ -13,15 +13,20 @@ // limitations under the License. import * as assert from 'assert'; +import * as semver from 'semver'; import {resolve} from 'path'; -import {parseOptions, FrameworkOptions} from '../src/options'; +import { + parseOptions, + FrameworkOptions, + requiredNodeJsVersionForLogExecutionID, +} from '../src/options'; describe('parseOptions', () => { interface TestData { name: string; cliOpts: string[]; envVars: {[key: string]: string}; - expectedOptions: Partial; + expectedOptions?: Partial; } const testData: TestData[] = [ @@ -31,6 +36,7 @@ describe('parseOptions', () => { envVars: {}, expectedOptions: { printHelp: true, + enableExecutionId: false, }, }, { @@ -39,6 +45,7 @@ describe('parseOptions', () => { envVars: {}, expectedOptions: { printHelp: true, + enableExecutionId: false, }, }, { @@ -51,6 +58,7 @@ describe('parseOptions', () => { sourceLocation: resolve(''), signatureType: 'http', printHelp: false, + enableExecutionId: false, }, }, { @@ -72,6 +80,7 @@ describe('parseOptions', () => { sourceLocation: resolve('/source'), signatureType: 'cloudevent', printHelp: false, + enableExecutionId: false, }, }, { @@ -89,6 +98,7 @@ describe('parseOptions', () => { sourceLocation: resolve('/source'), signatureType: 'cloudevent', printHelp: false, + enableExecutionId: false, }, }, { @@ -115,6 +125,7 @@ describe('parseOptions', () => { sourceLocation: resolve('/source'), signatureType: 'cloudevent', printHelp: false, + enableExecutionId: false, }, }, ]; @@ -123,6 +134,7 @@ describe('parseOptions', () => { it(testCase.name, () => { const options = parseOptions(testCase.cliOpts, testCase.envVars); const {expectedOptions} = testCase; + assert(expectedOptions); let opt: keyof FrameworkOptions; for (opt in expectedOptions) { assert.deepStrictEqual(expectedOptions[opt], options[opt]); @@ -130,6 +142,61 @@ describe('parseOptions', () => { }); }); + const cliOpts = ['bin/node', '/index.js']; + it('default disable execution id support', () => { + const options = parseOptions(cliOpts, {}); + assert.strictEqual(options.enableExecutionId, false); + }); + + it('disable execution id support by cli flag', () => { + const options = parseOptions( + ['bin/node', '/index.js', '--log-execution-id=false'], + {} + ); + assert.strictEqual(options.enableExecutionId, false); + }); + + it('disable execution id support by env var', () => { + const envVars = { + LOG_EXECUTION_ID: 'False', + }; + const options = parseOptions(cliOpts, envVars); + assert.strictEqual(options.enableExecutionId, false); + }); + + const executionIdTestData: TestData[] = [ + { + name: 'enable execution id support by cli flag', + cliOpts: ['bin/node', '/index.js', '--log-execution-id'], + envVars: {}, + }, + { + name: 'enable execution id support by env var', + cliOpts: ['bin/node', '/index.js'], + envVars: {LOG_EXECUTION_ID: 'True'}, + }, + { + name: 'execution id prioritizes cli flag over env var', + cliOpts: ['bin/node', '/index.js', '--log-execution-id=true'], + envVars: {LOG_EXECUTION_ID: 'False'}, + }, + ]; + + executionIdTestData.forEach(testCase => { + it(testCase.name, () => { + if ( + semver.lt(process.versions.node, requiredNodeJsVersionForLogExecutionID) + ) { + assert.throws(() => { + parseOptions(testCase.cliOpts, testCase.envVars); + }); + } else { + const options = parseOptions(testCase.cliOpts, testCase.envVars); + assert.strictEqual(options.enableExecutionId, true); + } + }); + }); + it('throws an exception for invalid signature types', () => { assert.throws(() => { parseOptions(['bin/node', 'index.js', '--signature-type=monkey']);