fix(auto-instrumentations-node): shutdown the SDK when the process ex…

…its normally (#2394)

Co-authored-by: Marc Pichler <[email protected]>

metapackages/auto-instrumentations-node/src/register.ts

@@ -40,9 +40,16 @@ try {
   );
 }
 
-process.on('SIGTERM', () => {
-  sdk
-    .shutdown()
-    .then(() => diag.debug('OpenTelemetry SDK terminated'))
-    .catch(error => diag.error('Error terminating OpenTelemetry SDK', error));
-});
+async function shutdown(): Promise<void> {
+  try {
+    await sdk.shutdown();
+    diag.debug('OpenTelemetry SDK terminated');
+  } catch (error) {
+    diag.error('Error terminating OpenTelemetry SDK', error);
+  }
+}
+
+// Gracefully shutdown SDK if a SIGTERM is received
+process.on('SIGTERM', shutdown);
+// Gracefully shutdown SDK if Node.js is exiting normally
+process.once('beforeExit', shutdown);

metapackages/auto-instrumentations-node/test/register.test.ts

@@ -14,42 +14,92 @@
  * limitations under the License.
  */
 
-import { spawnSync } from 'child_process';
+import { execFile, PromiseWithChild } from 'child_process';
 import * as assert from 'assert';
+import { promisify } from 'util';
+import { Readable } from 'stream';
 
-describe('Register', function () {
-  it('can load auto instrumentation from command line', () => {
-    const proc = spawnSync(
-      process.execPath,
-      ['--require', '../build/src/register.js', './test-app/app.js'],
-      {
-        cwd: __dirname,
-        timeout: 5000,
-        killSignal: 'SIGKILL', // SIGTERM is not sufficient to terminate some hangs
-        env: Object.assign({}, process.env, {
-          OTEL_NODE_RESOURCE_DETECTORS: 'none',
-          OTEL_TRACES_EXPORTER: 'console',
-          // nx (used by lerna run) defaults `FORCE_COLOR=true`, which in
-          // node v18.17.0, v20.3.0 and later results in ANSI color escapes
-          // in the ConsoleSpanExporter output that is checked below.
-          FORCE_COLOR: '0',
-        }),
+const execFilePromise = promisify(execFile);
+
+function runWithRegister(path: string): PromiseWithChild<{
+  stdout: string;
+  stderr: string;
+}> {
+  return execFilePromise(
+    process.execPath,
+    ['--require', '../build/src/register.js', path],
+    {
+      cwd: __dirname,
+      timeout: 1500,
+      killSignal: 'SIGKILL', // SIGTERM is not sufficient to terminate some hangs
+      env: Object.assign({}, process.env, {
+        OTEL_NODE_RESOURCE_DETECTORS: 'none',
+        OTEL_TRACES_EXPORTER: 'console',
+        OTEL_LOG_LEVEL: 'debug',
+        // nx (used by lerna run) defaults `FORCE_COLOR=true`, which in
+        // node v18.17.0, v20.3.0 and later results in ANSI color escapes
+        // in the ConsoleSpanExporter output that is checked below.
+        FORCE_COLOR: '0',
+      }),
+    }
+  );
+}
+
+function waitForString(stream: Readable, str: string): Promise<void> {
+  return new Promise((resolve, reject) => {
+    function check(chunk: Buffer): void {
+      if (chunk.includes(str)) {
+        resolve();
+        stream.off('data', check);
       }
+    }
+    stream.on('data', check);
+    stream.on('close', () =>
+      reject(`Stream closed without ever seeing "${str}"`)
+    );
+  });
+}
+
+describe('Register', function () {
+  it('can load auto instrumentation from command line', async () => {
+    const runPromise = runWithRegister('./test-app/app.js');
+    const { child } = runPromise;
+    const { stdout } = await runPromise;
+    assert.equal(child.exitCode, 0, `child.exitCode (${child.exitCode})`);
+    assert.equal(
+      child.signalCode,
+      null,
+      `child.signalCode (${child.signalCode})`
     );
-    assert.ifError(proc.error);
-    assert.equal(proc.status, 0, `proc.status (${proc.status})`);
-    assert.equal(proc.signal, null, `proc.signal (${proc.signal})`);
 
     assert.ok(
-      proc.stdout.includes(
+      stdout.includes(
         'OpenTelemetry automatic instrumentation started successfully'
       )
     );
 
+    assert.ok(
+      stdout.includes('OpenTelemetry SDK terminated'),
+      `Process output was missing message indicating successful shutdown, got stdout:\n${stdout}`
+    );
+
     // Check a span has been generated for the GET request done in app.js
+    assert.ok(stdout.includes("name: 'GET'"), 'console span output in stdout');
+  });
+
+  it('shuts down the NodeSDK when SIGTERM is received', async () => {
+    const runPromise = runWithRegister('./test-app/app-server.js');
+    const { child } = runPromise;
+    await waitForString(child.stdout!, 'Finshed request');
+    child.kill('SIGTERM');
+    const { stdout } = await runPromise;
+
     assert.ok(
-      proc.stdout.includes("name: 'GET'"),
-      'console span output in stdout'
+      stdout.includes('OpenTelemetry SDK terminated'),
+      `Process output was missing message indicating successful shutdown, got stdout:\n${stdout}`
     );
+
+    // Check a span has been generated for the GET request done in app.js
+    assert.ok(stdout.includes("name: 'GET'"), 'console span output in stdout');
   });
 });

metapackages/auto-instrumentations-node/test/test-app/app-server.js

@@ -0,0 +1,38 @@
+/*
+ * 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.
+ */
+
+//Used in register.test.ts to mimic a JS app that stays alive like a server.
+const http = require('http');
+
+const options = {
+  hostname: 'example.com',
+  port: 80,
+  path: '/',
+  method: 'GET',
+};
+
+const req = http.request(options);
+req.end();
+req.on('close', () => {
+  console.log('Finshed request');
+});
+
+// Make sure there is work on the event loop
+const handle = setInterval(() => {}, 1);
+// Gracefully shut down
+process.on('SIGTERM', () => {
+  clearInterval(handle);
+});