profiling-node icon indicating copy to clipboard operation
profiling-node copied to clipboard

No profiling data found

Open TreeOfLearning opened this issue 1 year ago • 6 comments

Is there an existing issue for this?

  • [X] I have checked for existing issues https://github.com/getsentry/profiling-node/issues
  • [X] I have reviewed the documentation https://docs.sentry.io/
  • [X] I am using the latest SDK release https://github.com/getsentry/profiling-node/releases

How do you use Sentry?

Self-hosted/on-premise

SDK Version

1.3.5

Link to Sentry event

No response

What environment is your node script running in?

$ node -v
v20.11.0

Running a node.js backend written in typescript that uses, amongst other things, type-graphql and apollo server. I have instrumentation set up and working.

The self hosted sentry instance is currently running 23.11.0, and profiling is enabled in sentry.conf.py.

How is your code deployed and bundled?

Currently just trying to get it to work locally, so it's just running tsc and then node. For production, we're creating a Docker image from the Node 20 base image.

Steps to Reproduce

Sentry init code:

Sentry.init({
  dsn: "http://<snip>",
  release: process.env.VERSION,
  tracesSampleRate: 1.0,
  profilesSampleRate: 1.0,
  environment: process.env.SENTRY_ENVIRONMENT ?? "local",
  integrations: [new ProfilingIntegration()],
});

Each incoming request starts instrumentation like this:

const transaction = Sentry.startTransaction({
          name: ctx.request.operationName ?? "graphql.request",
          op: "graphql",
        });
        Sentry.getCurrentScope().setSpan(transaction);

And ends like this:

return {
          willSendResponse: async (ctx) => {
            const ret = await ClearContainerCallback(ctx);
            transaction.end();
            return ret;
          },
        };

And this is definitely working, because I can see much useful data in the performance tab.

I've double checked and precompiled binaries do seem to be present: image

Confirmed (I think) by the check-build script:

$ node ./node_modules/@sentry/profiling-node/scripts/check-build.mjs
@sentry/profiling-node: Precompiled binary found, attempting to load <snip>/node_modules/@sentry/profiling-node/lib/sentry_cpu_profiler-darwin-arm64-115.node
@sentry/profiling-node: Precompiled binary found, skipping build from source.

Expected Result

Some profiling results to show up in the profiling tab...

Actual Result

No profiling results in the tab.

I'm at a bit of a loss as to how to debug this, so any suggestions would be welcome.

TreeOfLearning avatar Jan 23 '24 14:01 TreeOfLearning

@TreeOfLearning that is weird. Would you mind adding debug: true to your SDK and checking if there are any profiling related logs? Once that is enabled, the SDK integration will log if any of the profiles are discarded

JonasBa avatar Jan 23 '24 14:01 JonasBa

@TreeOfLearning that is weird. Would you mind adding debug: true to your SDK and checking if there are any profiling related logs? Once that is enabled, the SDK integration will log if any of the profiles are discarded

Sure, doesn't seem like there are any profiling related logs at all. Here's a complete log output from starting the server up and issuing one GraphQL query:

Sentry Logger [log]: Integration installed: InboundFilters
Sentry Logger [log]: Integration installed: FunctionToString
Sentry Logger [log]: Integration installed: LinkedErrors
Sentry Logger [log]: Integration installed: Console
Sentry Logger [log]: Integration installed: Http
Sentry Logger [log]: Integration installed: Undici
Sentry Logger [log]: Integration installed: OnUncaughtException
Sentry Logger [log]: Integration installed: OnUnhandledRejection
Sentry Logger [log]: Integration installed: ContextLines
Sentry Logger [log]: Integration installed: LocalVariables
Sentry Logger [log]: Integration installed: Context
Sentry Logger [log]: Integration installed: Modules
Sentry Logger [log]: Integration installed: RequestData
Sentry Logger [log]: Integration installed: ProfilingIntegration
🚀 Private API ready at http://localhost:4000/graphql
📢 Public API ready at http://localhost:4000/public
Version: v0.0.0
Sentry Logger [log]: [Tracing] starting auth transaction - Authenticate token
Sentry Logger [log]: [Tracing] Finishing auth transaction: Authenticate token.
Sentry Logger [log]: [Tracing] starting graphql transaction - ExampleQuery
Sentry Logger [log]: [Tracing] Starting 'graphql' span on transaction 'Query.pesTest' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'function' span on transaction 'func.PESTest.batchFind' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'db' span on transaction 'PESTest.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'db' span on transaction 'PESTest.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'function' span on transaction 'func.PESTest.batchFind' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'graphql' span on transaction 'PESTest.results' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'function' span on transaction 'func.Result.batchFind' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'db' span on transaction 'Result.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'db' span on transaction 'Result.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'function' span on transaction 'func.Result.batchFind' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'function' span on transaction 'func.Indicator.batchFind' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'db' span on transaction 'Indicator.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'db' span on transaction 'Indicator.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'graphql' span on transaction 'Indicator.model' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'graphql' span on transaction 'Indicator.model' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'function' span on transaction 'func.MLModel.batchFind' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Starting 'db' span on transaction 'MLModel.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'db' span on transaction 'MLModel.batchFind.db' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'graphql' span on transaction 'Indicator.model' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing 'function' span on transaction 'func.MLModel.batchFind' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Finishing graphql transaction: ExampleQuery.
Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'POST https://in.logs.betterstack.com/' (8af0fa79a585e4f1).
Sentry Logger [log]: [Tracing] Adding sentry-trace header 378ffabf5fb84ed49e66d74a01d7a316-969422ff6f89a138-1 to outgoing request to "https://in.logs.betterstack.com/": 

TreeOfLearning avatar Jan 23 '24 14:01 TreeOfLearning

@TreeOfLearning Can you share what versions of @sentry package versions you are using?

JonasBa avatar Jan 29 '24 17:01 JonasBa

@TreeOfLearning Can you share what versions of @sentry package versions you are using?

@JonasBa Of course:

    "@sentry/cli": "^2.26.0",
    "@sentry/node": "^7.94.1",
    "@sentry/profiling-node": "^1.3.5",
    "@sentry/tracing": "^7.94.1"

TreeOfLearning avatar Jan 29 '24 17:01 TreeOfLearning

Hi @JonasBa - any thoughts? :)

TreeOfLearning avatar Feb 21 '24 12:02 TreeOfLearning

@TreeOfLearning I'm puzzled as to why this happens. You are clearly generating transactions, but it seems as if the integration is never setup.

Would you mind upgrading @sentry/profiling-node to the latest version (afaik, you also don't need tracing anymore as it became a part of the core packages) and executing something like this:

const transaction = Sentry.startTransaction({name: "test"})
setTimeout(() => transaction.end(), 1000);

Alternatively, if you can provide a small reproducible example that we can debug, it would be even better.

JonasBa avatar Feb 22 '24 12:02 JonasBa