search

getsentry / profiling-node

The code for this repo now lives in https://github.com/getsentry/sentry-javascript/tree/develop/packages/profiling-node
MIT License
29 stars 10 forks source link

No profiling data found #238

Open TreeOfLearning opened 8 months ago

TreeOfLearning commented 8 months ago

Is there an existing issue for this?

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.

JonasBa commented 8 months ago

@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

TreeOfLearning commented 8 months ago

@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/":
JonasBa commented 8 months ago

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

TreeOfLearning commented 8 months ago

@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 commented 7 months ago

Hi @JonasBa - any thoughts? :)

JonasBa commented 7 months ago

@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.