Child processes sometimes freeze upon importing @sentry/profiling-node after upgrading Node.js from v18.20.8 to v22.14.0: Need suggestions to troubleshoot

[Frederick888]

We have an SQS queue consumer built on top of sqs-consumer. The actual work is done in Node.js child processes. The code roughly looks like:

// both main worker and child processes share these Sentry configs
import * as Sentry from '@sentry/node'
console.log('[Debug] Loaded @sentry/node')
import { nodeProfilingIntegration } from '@sentry/profiling-node'
console.log('[Debug] Loaded @sentry/profiling-node')
import { config } from '@src/config'
console.log('[Debug] Loaded @src/config')
import { getLogger } from '@src/logging'
console.log('[Debug] Loaded @src/logging')

Sentry.init({
  dsn,
  release,
  environment,
  tracesSampleRate: 0,
  integrations: [
    nodeProfilingIntegration(),
    Sentry.httpIntegration(),
    Sentry.expressIntegration(),
  ],
  beforeBreadcrumb: (breadcrumb) => {
    // filter out dd-trace-js
    if (breadcrumb.data?.url && typeof breadcrumb.data?.url === 'string' && breadcrumb.data?.url.includes(':8126')) {
      return null
    }

    return breadcrumb
  },
})

// main worker
const worker = Consumer.create({
  queueUrl: config.sqsJobQueueUrl,
  sqs: defaultSqsClient,
  terminateVisibilityTimeout: 5,
  attributeNames: ['All'],
  messageAttributeNames: ['All'],
  extendedAWSErrors: true,
  handleMessage: async (message) => {
    let extendReceiptTimeout
    try {
      const childPromise = new Promise((resolve, reject) => {
        const child = fork(__dirname + '/child', {
          stdio: 'inherit',
          timeout: config.sqsJobTimeout,
          serialization: 'advanced',
          env: process.env,
          execArgv: process.execArgv,
        })
        child.on('spawn', () => {
          child.send(message)
        })
        child.on('message', (childMessage: ChildMessage) => {
          if (childMessage.success) {
            resolve(childMessage)
          } else {
            reject(childMessage.error)
          }
        })
        child.on('exit', (code, signal) => {
          // ...
        })
        child.on('error', (err) => {
          // ...
        })
      })
      extendReceiptTimeout = setInterval(async () => {
        // extend SQS visibility timeout
      }, MESSAGE_RECEIPT_RENEWAL_INTERVAL)
      await childPromise
      // acknowledges the message
      return message
    } finally {
      if (extendReceiptTimeout) {
        clearInterval(extendReceiptTimeout)
      }
    }
  },
})

We use @sentry/node v8.55.0 and sentry.io.

After upgrading Node.js from v18.20.8 to v22.14.0, the child process occasionally freezes on start. I got into the K8s container, and the child process was still running, consuming a small amount of CPU, but it just went silent.

USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
node          42  1.7  0.0 33600188 241120 ?     Sl   07:19   0:10 /usr/local/bin/node --enable-source-maps --stack-size=4096 ./dist
node        1670  1.5  0.0 12309668 185680 ?     Sl   07:27   0:01 /usr/local/bin/node --enable-source-maps --stack-size=4096 /app/packages/worker/dist/child

Initially I thought it was some issue when calling Sentry.init() and tried things like enabling Sentry NodeOptions.debug, disabling ProcessAndThreadBreadcrumbs, setting env var DEBUG='*', downgrading require-in-the-middle from v7.4.0 to v7.3.0, etc. But later after adding some console.log()s, I realised that it was actually import { nodeProfilingIntegration } from '@sentry/profiling-node' that got stuck somehow, where I never saw the log from console.log('[Debug] Loaded @sentry/profiling-node').

The next thing I'd like to try is probably disabling profiling support from dd-trace-js. But before I sink more time into this issue, especially given that I'm relatively new to Node.js, I'm curious:

1. Is there any existing relevant issue that my search-fu didn't find?
2. Is combining dd-trace-js and Sentry a known bad practice?
3. Any suggestions on debugging imports?

Thank you.

[Frederick888]

I patched profiling-node using yarn patch to add some console.log()s:

diff --git a/lib/cjs/index.js b/lib/cjs/index.js
index 329811b0ce9f36450eecdd77598cdbaa471630b8..8b442a5b3f6fc4bc20834fe34b9b2f017db7c289 100644
--- a/lib/cjs/index.js
+++ b/lib/cjs/index.js
@@ -7,17 +7,29 @@ var {
 Object.defineProperty(exports, '__esModule', { value: true });
 
 const core = require('@sentry/core');
+console.log('[Frederick Debug] Loaded @sentry/core');
 const node_module = require('node:module');
+console.log('[Frederick Debug] Loaded node:module');
 const node_os = require('node:os');
+console.log('[Frederick Debug] Loaded node:os');
 const node_path = require('node:path');
+console.log('[Frederick Debug] Loaded node:path');
 const node_process = require('node:process');
+console.log('[Frederick Debug] Loaded node:process');
 const node_url = require('node:url');
+console.log('[Frederick Debug] Loaded node:url');
 const node_worker_threads = require('node:worker_threads');
+console.log('[Frederick Debug] Loaded node:worker_threads');
 const detectLibc = require('detect-libc');
+console.log('[Frederick Debug] Loaded detect-libc');
 const nodeAbi = require('node-abi');
+console.log('[Frederick Debug] Loaded node-abi');
 const os = require('os');
+console.log('[Frederick Debug] Loaded os');
 const process$1 = require('process');
+console.log('[Frederick Debug] Loaded process');
 const worker_threads = require('worker_threads');
+console.log('[Frederick Debug] Loaded worker_threads');
 
 var _documentCurrentScript = typeof document !== 'undefined' ? document.currentScript : null;
 /**
@@ -38,6 +50,7 @@ const identifier = [platform, arch, stdlib, abi].filter(c => c !== undefined &&
  */
 // eslint-disable-next-line complexity
 function importCppBindingsModule() {
+  console.log('[Frederick Debug] importCppBindingsModule starting');
   // We need to work around using import.meta.url directly with import.meta.url because jest complains about it.
   const importMetaUrl =
     typeof (typeof document === 'undefined' ? require('u' + 'rl').pathToFileURL(__filename).href : (_documentCurrentScript && _documentCurrentScript.tagName.toUpperCase() === 'SCRIPT' && _documentCurrentScript.src || new URL('index.js', document.baseURI).href)) !== 'undefined'
@@ -52,12 +65,14 @@ function importCppBindingsModule() {
   // If a binary path is specified, use that.
   if (node_process.env['SENTRY_PROFILER_BINARY_PATH']) {
     const envPath = node_process.env['SENTRY_PROFILER_BINARY_PATH'];
+    console.log(`[Frederick Debug] importCppBindingsModule requiring ${envPath}`);
     return createdRequire(envPath);
   }
 
   // If a user specifies a different binary dir, they are in control of the binaries being moved there
   if (node_process.env['SENTRY_PROFILER_BINARY_DIR']) {
     const binaryPath = node_path.join(node_path.resolve(node_process.env['SENTRY_PROFILER_BINARY_DIR']), `sentry_cpu_profiler-${identifier}`);
+    console.log(`[Frederick Debug] importCppBindingsModule requiring ${binaryPath}.node`);
     return createdRequire(`${binaryPath}.node`);
   }
 
@@ -66,30 +81,38 @@ function importCppBindingsModule() {
   if (platform === 'darwin') {
     if (arch === 'x64') {
       if (abi === '93') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-x64-93.node');
         return createdRequire('../sentry_cpu_profiler-darwin-x64-93.node');
       }
       if (abi === '108') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-x64-108.node');
         return createdRequire('../sentry_cpu_profiler-darwin-x64-108.node');
       }
       if (abi === '115') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-x64-115.node');
         return createdRequire('../sentry_cpu_profiler-darwin-x64-115.node');
       }
       if (abi === '127') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-x64-127.node');
         return createdRequire('../sentry_cpu_profiler-darwin-x64-127.node');
       }
     }
 
     if (arch === 'arm64') {
       if (abi === '93') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-arm64-93.node');
         return createdRequire('../sentry_cpu_profiler-darwin-arm64-93.node');
       }
       if (abi === '108') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-arm64-108.node');
         return createdRequire('../sentry_cpu_profiler-darwin-arm64-108.node');
       }
       if (abi === '115') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-arm64-115.node');
         return createdRequire('../sentry_cpu_profiler-darwin-arm64-115.node');
       }
       if (abi === '127') {
+        console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-darwin-arm64-127.node');
         return createdRequire('../sentry_cpu_profiler-darwin-arm64-127.node');
       }
     }
@@ -116,29 +139,37 @@ function importCppBindingsModule() {
     if (arch === 'x64') {
       if (stdlib === 'musl') {
         if (abi === '93') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-musl-93.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-musl-93.node');
         }
         if (abi === '108') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-musl-108.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-musl-108.node');
         }
         if (abi === '115') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-musl-115.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-musl-115.node');
         }
         if (abi === '127') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-musl-127.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-musl-127.node');
         }
       }
       if (stdlib === 'glibc') {
         if (abi === '93') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-glibc-93.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-glibc-93.node');
         }
         if (abi === '108') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-glibc-108.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-glibc-108.node');
         }
         if (abi === '115') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-glibc-115.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-glibc-115.node');
         }
         if (abi === '127') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-glibc-127.node');
           return createdRequire('../sentry_cpu_profiler-linux-x64-glibc-127.node');
         }
       }
@@ -146,30 +177,38 @@ function importCppBindingsModule() {
     if (arch === 'arm64') {
       if (stdlib === 'musl') {
         if (abi === '93') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-musl-93.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-musl-93.node');
         }
         if (abi === '108') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-musl-108.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-musl-108.node');
         }
         if (abi === '115') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-musl-115.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-musl-115.node');
         }
         if (abi === '127') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-musl-127.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-musl-127.node');
         }
       }
 
       if (stdlib === 'glibc') {
         if (abi === '93') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-glibc-93.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-glibc-93.node');
         }
         if (abi === '108') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-glibc-108.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-glibc-108.node');
         }
         if (abi === '115') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-glibc-115.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-glibc-115.node');
         }
         if (abi === '127') {
+          console.log('[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-arm64-glibc-127.node');
           return createdRequire('../sentry_cpu_profiler-linux-arm64-glibc-127.node');
         }
       }
@@ -177,10 +216,12 @@ function importCppBindingsModule() {
   }
 
   const built_from_source_path = node_path.resolve(esmCompatibleDirname, '..', `sentry_cpu_profiler-${identifier}`);
+  console.log(`[Frederick Debug] importCppBindingsModule requiring ${built_from_source_path}.node`);
   return createdRequire(`${built_from_source_path}.node`);
 }
 
 const PrivateCpuProfilerBindings = importCppBindingsModule();
+console.log('[Frederick Debug] Calling importCppBindingsModule');
 
 class Bindings  {
    startProfiling(name) {
@@ -224,6 +265,7 @@ class Bindings  {
 }
 
 const CpuProfilerBindings = new Bindings();
+console.log('[Frederick Debug] Created Bindings');
 
 const NODE_VERSION = core.parseSemver(process.versions.node) ;
 const NODE_MAJOR = NODE_VERSION.major;
@@ -247,6 +289,7 @@ const VERSION = os.version();
 const TYPE = os.type();
 const MODEL = machine;
 const ARCH = os.arch();
+console.log('[Frederick Debug] Created constants');
 
 /**
  * Checks if the profile is a raw profile or a profile enriched with thread information.
@@ -258,6 +301,7 @@ function isRawThreadCpuProfile(
 ) {
   return !('thread_metadata' in profile);
 }
+console.log('[Frederick Debug] Defined isRawThreadCpuProfile');
 
 /**
  * Enriches the profile with threadId of the current thread.
@@ -284,6 +328,7 @@ function enrichWithThreadInformation(
     },
   } ;
 }
+console.log('[Frederick Debug] Defined enrichWithThreadInformation');
 
 /**
  * Creates a profiling envelope item, if the profile does not pass validation, returns null.
@@ -306,6 +351,7 @@ function createProfilingEvent(client, profile, event) {
     profile_id: profile.profile_id,
   });
 }
+console.log('[Frederick Debug] Defined createProfilingEvent');
 
 /**
  * Create a profile
@@ -375,6 +421,7 @@ function createProfilePayload(
 
   return profile;
 }
+console.log('[Frederick Debug] Defined createProfilePayload');
 
 /**
  * Create a profile chunk from raw thread profile
@@ -425,6 +472,7 @@ function createProfileChunkPayload(
 
   return profile;
 }
+console.log('[Frederick Debug] Defined createProfileChunkPayload');
 
 /**
  * Creates a profiling chunk envelope item, if the profile does not pass validation, returns null.
@@ -449,6 +497,7 @@ function createProfilingChunkEvent(
     sdk,
   });
 }
+console.log('[Frederick Debug] Defined createProfilingChunkEvent');
 
 /**
  * Checks the given sample rate to make sure it is valid type and value (a boolean, or a number between 0 and 1).
@@ -479,6 +528,7 @@ function isValidSampleRate(rate) {
   }
   return true;
 }
+console.log('[Frederick Debug] Defined isValidSampleRate');
 
 /**
  * Checks if the profile is valid and can be sent to Sentry.
@@ -501,6 +551,7 @@ function isValidProfile(profile) {
 
   return true;
 }
+console.log('[Frederick Debug] Defined isValidProfile');
 
 /**
  * Checks if the profile chunk is valid and can be sent to Sentry.
@@ -519,6 +570,7 @@ function isValidProfileChunk(profile) {
 
   return true;
 }
+console.log('[Frederick Debug] Defined isValidProfileChunk');
 
 /**
  * Adds items to envelope if they are not already present - mutates the envelope.
@@ -537,6 +589,7 @@ function addProfilesToEnvelope(envelope, profiles) {
   }
   return envelope;
 }
+console.log('[Frederick Debug] Defined addProfilesToEnvelope');
 
 /**
  * Finds transactions with profile_id context in the envelope
@@ -571,6 +624,7 @@ function findProfiledTransactionsFromEnvelope(envelope) {
 
   return events;
 }
+console.log('[Frederick Debug] Defined findProfiledTransactionsFromEnvelope');
 
 /**
  * Creates event envelope headers for a profile chunk. This is separate from createEventEnvelopeHeaders util
@@ -588,6 +642,7 @@ function createEventEnvelopeHeaders(
     ...(!!tunnel && dsn && { dsn: core.dsnToString(dsn) }),
   };
 }
+console.log('[Frederick Debug] Defined createEventEnvelopeHeaders');
 
 /**
  * Creates a standalone profile_chunk envelope.
@@ -606,6 +661,7 @@ function makeProfileChunkEnvelope(
     [profileChunkHeader, chunk],
   ]);
 }
+console.log('[Frederick Debug] Defined makeProfileChunkEnvelope');
 
 /**
  * Cross reference profile collected resources with debug_ids and return a list of debug images.
@@ -621,6 +677,7 @@ function applyDebugMetadata(client, resource_paths) {
 
   return core.getDebugImagesForResources(options.stackParser, resource_paths);
 }
+console.log('[Frederick Debug] Defined applyDebugMetadata');
 
 const MAX_PROFILE_DURATION_MS = 30 * 1000;
 
@@ -715,6 +772,7 @@ function maybeProfileSpan(
   // so that we can still see the profile_id in the transaction context
   return profile_id;
 }
+console.log('[Frederick Debug] Defined maybeProfileSpan');
 
 /**
  * Stops the profiler for profile_id and returns the profile
@@ -745,6 +803,7 @@ function stopSpanProfile(span, profile_id) {
   profile.profile_id = profile_id;
   return profile;
 }
+console.log('[Frederick Debug] Defined stopSpanProfile');
 
 var ProfileFormat;(function (ProfileFormat) {
   const THREAD = 0; ProfileFormat[ProfileFormat["THREAD"] = THREAD] = "THREAD";
@@ -758,12 +817,14 @@ const PROFILE_TIMEOUTS = {};
 function addToProfileQueue(profile_id, profile) {
   PROFILE_MAP.set(profile_id, profile);
 }
+console.log('[Frederick Debug] Defined addToProfileQueue');
 
 function takeFromProfileQueue(profile_id) {
   const profile = PROFILE_MAP.get(profile_id);
   PROFILE_MAP.remove(profile_id);
   return profile;
 }
+console.log('[Frederick Debug] Defined takeFromProfileQueue');
 
 /**
  * Instruments the client to automatically invoke the profiler on span start and stop events.
@@ -874,6 +935,7 @@ function setupAutomatedSpanProfiling(client) {
     addProfilesToEnvelope(envelope, profilesToAddToEnvelope);
   });
 }
+console.log('[Frederick Debug] Defined setupAutomatedSpanProfiling');
 
 class ContinuousProfiler {constructor() { ContinuousProfiler.prototype.__init.call(this);ContinuousProfiler.prototype.__init2.call(this); }
 
@@ -1138,6 +1200,7 @@ class ContinuousProfiler {constructor() { ContinuousProfiler.prototype.__init.ca
     this._chunkData = undefined;
   }
 }
+console.log('[Frederick Debug] Defined ContinuousProfiler');
 
 /** Exported only for tests. */
 const _nodeProfilingIntegration = (() => {
@@ -1187,6 +1250,7 @@ const _nodeProfilingIntegration = (() => {
     },
   };
 }) ;
+console.log('[Frederick Debug] Defined _nodeProfilingIntegration');
 
 /**
  * We need this integration in order to send data to Sentry. We hook into the event processor
@@ -1195,6 +1259,7 @@ const _nodeProfilingIntegration = (() => {
  * and delete the profile from the transaction metadata.
  */
 const nodeProfilingIntegration = core.defineIntegration(_nodeProfilingIntegration);
+console.log('[Frederick Debug] Defined nodeProfilingIntegration');
 
 exports.nodeProfilingIntegration = nodeProfilingIntegration;
 //# sourceMappingURL=index.js.map

And when the issue happened, the log stopped at:

[Frederick Debug] Loaded @sentry/core
[Frederick Debug] Loaded node:module
[Frederick Debug] Loaded node:os
[Frederick Debug] Loaded node:path
[Frederick Debug] Loaded node:process
[Frederick Debug] Loaded node:url
[Frederick Debug] Loaded node:worker_threads
[Frederick Debug] Loaded detect-libc
[Frederick Debug] Loaded node-abi
[Frederick Debug] Loaded os
[Frederick Debug] Loaded process
[Frederick Debug] Loaded worker_threads
[Frederick Debug] importCppBindingsModule starting
[Frederick Debug] importCppBindingsModule requiring ../sentry_cpu_profiler-linux-x64-glibc-127.node

To double check this, we are probably gonna remove @sentry/profiling-node for now to see if this issue still happens.