From 3ca874e45ebf4623e76cbe9305e55e820b6e03fd Mon Sep 17 00:00:00 2001 From: Marc Hassan Date: Mon, 27 Feb 2023 01:37:45 -0500 Subject: [PATCH] fix(instrumentation-fs): fix instrumentation of `fs/promises` (#1375) * fix(instrumentation-fs): fix instrumentation of `fs/promises` * Revert "fix(instrumentation-fs): fix instrumentation of `fs/promises`" This reverts commit 90d9f0d68960ef647bbe5b7347ad6c97f936651e. * fix(instrumentation-fs): fix instrumentation of `fs/promises` * chore(instrumentation-fs): fix lint error * chore(instrumentation-fs): hard-code `R_OK` value for node 14 * chore(instrumentation-fs): fix supported version for `fs/promises` * chore(instrumentation-fs): incorporate changes from #1332 * chore(instrumentation-fs): consolidate common test utilities --------- Co-authored-by: Haddas Bronfman <85441461+haddasbronfman@users.noreply.github.com> --- .../instrumentation-fs/src/instrumentation.ts | 33 +++- .../test/{index.test.ts => fs.test.ts} | 61 +------ .../test/{hooks.test.ts => fsHooks.test.ts} | 0 .../test/fsPromises.test.ts | 153 ++++++++++++++++++ .../test/fsPromisesHooks.test.ts | 122 ++++++++++++++ plugins/node/instrumentation-fs/test/utils.ts | 77 +++++++++ 6 files changed, 386 insertions(+), 60 deletions(-) rename plugins/node/instrumentation-fs/test/{index.test.ts => fs.test.ts} (89%) rename plugins/node/instrumentation-fs/test/{hooks.test.ts => fsHooks.test.ts} (100%) create mode 100644 plugins/node/instrumentation-fs/test/fsPromises.test.ts create mode 100644 plugins/node/instrumentation-fs/test/fsPromisesHooks.test.ts create mode 100644 plugins/node/instrumentation-fs/test/utils.ts diff --git a/plugins/node/instrumentation-fs/src/instrumentation.ts b/plugins/node/instrumentation-fs/src/instrumentation.ts index 73059be47c3..048b8d7b34b 100644 --- a/plugins/node/instrumentation-fs/src/instrumentation.ts +++ b/plugins/node/instrumentation-fs/src/instrumentation.ts @@ -39,6 +39,7 @@ import { promisify } from 'util'; import { indexFs } from './utils'; type FS = typeof fs; +type FSPromises = (typeof fs)['promises']; /** * This is important for 2-level functions like `realpath.native` to retain the 2nd-level @@ -55,7 +56,10 @@ export default class FsInstrumentation extends InstrumentationBase { super('@opentelemetry/instrumentation-fs', VERSION, config); } - init(): InstrumentationNodeModuleDefinition[] { + init(): ( + | InstrumentationNodeModuleDefinition + | InstrumentationNodeModuleDefinition + )[] { return [ new InstrumentationNodeModuleDefinition( 'fs', @@ -129,6 +133,33 @@ export default class FsInstrumentation extends InstrumentationBase { } } ), + new InstrumentationNodeModuleDefinition( + 'fs/promises', + ['*'], + (fsPromises: FSPromises) => { + this._diag.debug('Applying patch for fs/promises'); + for (const fName of PROMISE_FUNCTIONS) { + if (isWrapped(fsPromises[fName])) { + this._unwrap(fsPromises, fName); + } + this._wrap( + fsPromises, + fName, + this._patchPromiseFunction.bind(this, fName) + ); + } + return fsPromises; + }, + (fsPromises: FSPromises) => { + if (fsPromises === undefined) return; + this._diag.debug('Removing patch for fs/promises'); + for (const fName of PROMISE_FUNCTIONS) { + if (isWrapped(fsPromises[fName])) { + this._unwrap(fsPromises, fName); + } + } + } + ), ]; } diff --git a/plugins/node/instrumentation-fs/test/index.test.ts b/plugins/node/instrumentation-fs/test/fs.test.ts similarity index 89% rename from plugins/node/instrumentation-fs/test/index.test.ts rename to plugins/node/instrumentation-fs/test/fs.test.ts index c29fb0b40a5..e8f97b6ab29 100644 --- a/plugins/node/instrumentation-fs/test/index.test.ts +++ b/plugins/node/instrumentation-fs/test/fs.test.ts @@ -13,12 +13,11 @@ * See the License for the specific language governing permissions and * limitations under the License. */ -import { context, trace, SpanStatusCode, SpanKind } from '@opentelemetry/api'; +import { context, trace } from '@opentelemetry/api'; import { AsyncHooksContextManager } from '@opentelemetry/context-async-hooks'; import { BasicTracerProvider, InMemorySpanExporter, - ReadableSpan, SimpleSpanProcessor, } from '@opentelemetry/sdk-trace-base'; import * as assert from 'assert'; @@ -34,6 +33,7 @@ import { SYNC_FUNCTIONS, } from '../src/constants'; import { indexFs, splitTwoLevels } from '../src/utils'; +import { assertSpans, makeRootSpanName } from './utils'; const TEST_ATTRIBUTE = 'test.attr'; const TEST_VALUE = 'test.attr.value'; @@ -149,16 +149,6 @@ describe('fs instrumentation', () => { ]); }); }; - const makeRootSpanName = (name: FMember): string => { - let rsn: string; - if (Array.isArray(name)) { - rsn = `${name[0]}.${name[1]}`; - } else { - rsn = `${name}`; - } - rsn = `${rsn} test span`; - return rsn; - }; const callbackTest: TestCreator = ( name: FMember, @@ -443,50 +433,3 @@ describe('fs instrumentation', () => { }); }); }); - -const assertSpans = (spans: ReadableSpan[], expected: any) => { - assert.strictEqual( - spans.length, - expected.length, - `Expected ${expected.length} spans, got ${spans.length}(${spans - .map((s: any) => `"${s.name}"`) - .join(', ')})` - ); - - spans.forEach((span, i) => { - assertSpan(span, expected[i]); - }); -}; - -const assertSpan = (span: ReadableSpan, expected: any) => { - assert(span); - assert.strictEqual(span.name, expected.name); - assert.strictEqual( - span.kind, - SpanKind.INTERNAL, - 'Expected to be of INTERNAL kind' - ); - if (expected.parentSpan) { - assert.strictEqual( - span.parentSpanId, - expected.parentSpan.spanContext().spanId - ); - } - if (expected.attributes) { - assert.deepEqual(span.attributes, expected.attributes); - } - if (expected.error) { - assert( - expected.error.test(span.status.message), - `Expected "${span.status.message}" to match ${expected.error}` - ); - assert.strictEqual(span.status.code, SpanStatusCode.ERROR); - } else { - assert.strictEqual( - span.status.code, - SpanStatusCode.UNSET, - 'Expected status to be unset' - ); - assert.strictEqual(span.status.message, undefined); - } -}; diff --git a/plugins/node/instrumentation-fs/test/hooks.test.ts b/plugins/node/instrumentation-fs/test/fsHooks.test.ts similarity index 100% rename from plugins/node/instrumentation-fs/test/hooks.test.ts rename to plugins/node/instrumentation-fs/test/fsHooks.test.ts diff --git a/plugins/node/instrumentation-fs/test/fsPromises.test.ts b/plugins/node/instrumentation-fs/test/fsPromises.test.ts new file mode 100644 index 00000000000..604eb8c61bc --- /dev/null +++ b/plugins/node/instrumentation-fs/test/fsPromises.test.ts @@ -0,0 +1,153 @@ +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +import { context, trace } from '@opentelemetry/api'; +import { AsyncHooksContextManager } from '@opentelemetry/context-async-hooks'; +import { + BasicTracerProvider, + InMemorySpanExporter, + SimpleSpanProcessor, +} from '@opentelemetry/sdk-trace-base'; +import * as assert from 'assert'; +import Instrumentation from '../src'; +import * as sinon from 'sinon'; +import type * as FSPromisesType from 'fs/promises'; +import tests, { FsFunction, TestCase, TestCreator } from './definitions'; +import type { FPMember, EndHook } from '../src/types'; +import { assertSpans, makeRootSpanName } from './utils'; + +const supportsPromises = + parseInt(process.versions.node.split('.')[0], 10) >= 14; + +const TEST_ATTRIBUTE = 'test.attr'; +const TEST_VALUE = 'test.attr.value'; + +const endHook = sinon.spy((fnName, { args, span }) => { + span.setAttribute(TEST_ATTRIBUTE, TEST_VALUE); +}); +const pluginConfig = { + endHook, +}; +const provider = new BasicTracerProvider(); +const tracer = provider.getTracer('default'); +const memoryExporter = new InMemorySpanExporter(); +provider.addSpanProcessor(new SimpleSpanProcessor(memoryExporter)); + +if (supportsPromises) { + describe('fs/promises instrumentation', () => { + let contextManager: AsyncHooksContextManager; + let fsPromises: typeof FSPromisesType; + let plugin: Instrumentation; + + beforeEach(async () => { + contextManager = new AsyncHooksContextManager(); + context.setGlobalContextManager(contextManager.enable()); + plugin = new Instrumentation(pluginConfig); + plugin.setTracerProvider(provider); + plugin.enable(); + fsPromises = require('fs/promises'); + assert.strictEqual(memoryExporter.getFinishedSpans().length, 0); + }); + + afterEach(() => { + plugin.disable(); + memoryExporter.reset(); + context.disable(); + }); + + const promiseTest: TestCreator = ( + name: FPMember, + args, + { error, result, resultAsError = null, hasPromiseVersion = true }, + spans + ) => { + if (!hasPromiseVersion) return; + const rootSpanName = makeRootSpanName(name); + it(`promises.${name} ${error ? 'error' : 'success'}`, async () => { + const rootSpan = tracer.startSpan(rootSpanName); + + assert.strictEqual(memoryExporter.getFinishedSpans().length, 0); + await context + .with(trace.setSpan(context.active(), rootSpan), () => { + // eslint-disable-next-line node/no-unsupported-features/node-builtins + assert( + typeof fsPromises[name] === 'function', + `Expected fsPromises.${name} to be a function` + ); + return Reflect.apply(fsPromises[name], fsPromises, args); + }) + .then((actualResult: any) => { + if (error) { + assert.fail(`promises.${name} did not reject`); + } else { + assert.deepEqual(actualResult, result ?? resultAsError); + } + }) + .catch((actualError: any) => { + assert( + actualError instanceof Error, + `Expected caugth error to be instance of Error. Got ${actualError}` + ); + if (error) { + assert( + error.test(actualError?.message ?? ''), + `Expected "${actualError?.message}" to match ${error}` + ); + } else { + actualError.message = `Did not expect promises.${name} to reject: ${actualError.message}`; + assert.fail(actualError); + } + }); + rootSpan.end(); + assertSpans(memoryExporter.getFinishedSpans(), [ + ...spans.map((s: any) => { + const spanName = s.name.replace(/%NAME/, name); + const attributes = { + ...(s.attributes ?? {}), + }; + attributes[TEST_ATTRIBUTE] = TEST_VALUE; + return { + ...s, + name: spanName, + attributes, + }; + }), + { name: rootSpanName }, + ]); + }); + }; + + const selection: TestCase[] = tests.filter( + ([name, , , , options = {}]) => + options.promise !== false && name !== ('exists' as FsFunction) + ); + + describe('Instrumentation enabled', () => { + selection.forEach(([name, args, result, spans]) => { + promiseTest(name as FPMember, args, result, spans); + }); + }); + + describe('Instrumentation disabled', () => { + beforeEach(() => { + plugin.disable(); + }); + + selection.forEach(([name, args, result]) => { + promiseTest(name as FPMember, args, result, []); + }); + }); + }); +} diff --git a/plugins/node/instrumentation-fs/test/fsPromisesHooks.test.ts b/plugins/node/instrumentation-fs/test/fsPromisesHooks.test.ts new file mode 100644 index 00000000000..42d31b81308 --- /dev/null +++ b/plugins/node/instrumentation-fs/test/fsPromisesHooks.test.ts @@ -0,0 +1,122 @@ +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +import { + BasicTracerProvider, + InMemorySpanExporter, + SimpleSpanProcessor, +} from '@opentelemetry/sdk-trace-base'; +import * as assert from 'assert'; +import Instrumentation from '../src'; +import * as sinon from 'sinon'; +import type * as FSPromisesType from 'fs/promises'; +import type { FsInstrumentationConfig } from '../src/types'; + +const supportsPromises = + parseInt(process.versions.node.split('.')[0], 10) >= 14; + +const createHookError = new Error('createHook failed'); +const createHook = sinon.spy((_functionName: string) => { + throw createHookError; +}); +const endHookError = new Error('endHook failed'); +const endHook = sinon.spy((_functionName: string) => { + throw endHookError; +}); +const pluginConfig = { + createHook, + endHook, +}; + +const provider = new BasicTracerProvider(); +const memoryExporter = new InMemorySpanExporter(); +provider.addSpanProcessor(new SimpleSpanProcessor(memoryExporter)); + +const assertNotHookError = (err?: Error | null) => { + assert.ok( + err && + err.message !== createHookError.message && + err.message !== endHookError.message, + 'Hook error shadowed the error from the original call' + ); +}; + +const assertSuccessfulCallHooks = (expectedFunctionName: string) => { + const createHookCall = createHook.withArgs(expectedFunctionName); + sinon.assert.called(createHookCall); + sinon.assert.threw(createHookCall, createHookError); + + const endHookCall = endHook.withArgs(expectedFunctionName); + sinon.assert.called(endHookCall); + sinon.assert.threw(endHookCall, endHookError); + assert( + !(endHookCall.getCall(0).args as any)[1].error, + 'Did not expect an error' + ); +}; + +const assertFailingCallHooks = (expectedFunctionName: string) => { + const createHookCall = createHook.withArgs(expectedFunctionName); + sinon.assert.called(createHookCall); + sinon.assert.threw(createHookCall, createHookError); + + const endHookCall = endHook.withArgs(expectedFunctionName); + sinon.assert.called(endHookCall); + sinon.assert.threw(endHookCall, endHookError); + assert((endHookCall.getCall(0).args as any)[1].error, 'Expected an error'); +}; + +// This should equal `fs.constants.R_OK`. +// We are hard-coding this because Node 14 and below does not include `constants` in `fsPromises`. +const fsConstantsR_OK = 4; + +if (supportsPromises) { + describe('fs/promises instrumentation: hooks', () => { + let plugin: Instrumentation; + let fsPromises: typeof FSPromisesType; + + beforeEach(async () => { + plugin = new Instrumentation(pluginConfig); + plugin.setTracerProvider(provider); + plugin.setConfig(pluginConfig as FsInstrumentationConfig); + plugin.enable(); + fsPromises = require('fs/promises'); + createHook.resetHistory(); + endHook.resetHistory(); + assert.strictEqual(memoryExporter.getFinishedSpans().length, 0); + }); + + afterEach(() => { + plugin.disable(); + memoryExporter.reset(); + }); + + it('should not fail the original successful call when hooks throw', async () => { + // eslint-disable-next-line node/no-unsupported-features/node-builtins + await fsPromises.access('./test/fixtures/readtest', fsConstantsR_OK); + + assertSuccessfulCallHooks('access'); + }); + + it('should not shadow the error from original call when hooks throw', async () => { + // eslint-disable-next-line node/no-unsupported-features/node-builtins + await fsPromises + .access('./test/fixtures/readtest-404', fsConstantsR_OK) + .catch(assertNotHookError); + + assertFailingCallHooks('access'); + }); + }); +} diff --git a/plugins/node/instrumentation-fs/test/utils.ts b/plugins/node/instrumentation-fs/test/utils.ts new file mode 100644 index 00000000000..a3f2cd33f7d --- /dev/null +++ b/plugins/node/instrumentation-fs/test/utils.ts @@ -0,0 +1,77 @@ +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +import { ReadableSpan } from '@opentelemetry/sdk-trace-base'; +import * as assert from 'assert'; +import { SpanKind, SpanStatusCode } from '@opentelemetry/api'; +import type { FMember } from '../src/types'; + +export const assertSpans = (spans: ReadableSpan[], expected: any) => { + assert.strictEqual( + spans.length, + expected.length, + `Expected ${expected.length} spans, got ${spans.length}(${spans + .map((s: any) => `"${s.name}"`) + .join(', ')})` + ); + + spans.forEach((span, i) => { + assertSpan(span, expected[i]); + }); +}; + +const assertSpan = (span: ReadableSpan, expected: any) => { + assert(span); + assert.strictEqual(span.name, expected.name); + assert.strictEqual( + span.kind, + SpanKind.INTERNAL, + 'Expected to be of INTERNAL kind' + ); + if (expected.parentSpan) { + assert.strictEqual( + span.parentSpanId, + expected.parentSpan.spanContext().spanId + ); + } + if (expected.attributes) { + assert.deepEqual(span.attributes, expected.attributes); + } + if (expected.error) { + assert( + expected.error.test(span.status.message), + `Expected "${span.status.message}" to match ${expected.error}` + ); + assert.strictEqual(span.status.code, SpanStatusCode.ERROR); + } else { + assert.strictEqual( + span.status.code, + SpanStatusCode.UNSET, + 'Expected status to be unset' + ); + assert.strictEqual(span.status.message, undefined); + } +}; + +export const makeRootSpanName = (name: FMember): string => { + let rsn: string; + if (Array.isArray(name)) { + rsn = `${name[0]}.${name[1]}`; + } else { + rsn = `${name}`; + } + rsn = `${rsn} test span`; + return rsn; +};