Repository navigation
Profiles not sent by express SDK #14655
Description
Is there an existing issue for this?
- I have checked for existing issues https://github.com/getsentry/sentry-javascript/issues
- I have reviewed the documentation https://docs.sentry.io/
- I am using the latest SDK release https://github.com/getsentry/sentry-javascript/releases
How do you use Sentry?
Sentry Saas (sentry.io)
Which SDK are you using?
@sentry/node
SDK Version
8.42.0
Framework Version
express v4.18.2
Link to Sentry event
No response
Reproduction Example/SDK Setup
instrument.js
const Sentry = require("@sentry/node");
const { nodeProfilingIntegration } = require("@sentry/profiling-node");
// Ensure to call this before requiring any other modules!
Sentry.init({
debug:true,
dsn: "....",
integrations: [
// Add our Profiling integration
nodeProfilingIntegration(),
],
// Add Tracing by setting tracesSampleRate
// We recommend adjusting this value in production
tracesSampleRate: 1.0,
// Set sampling rate for profiling
// This is relative to tracesSampleRate
profilesSampleRate: 1.0,
});
app code:
require("./instrument");
// Now require other modules
const express = require("express");
const Sentry = require("@sentry/node");
const app = express()
const port = 8000
const http = require('http')
function bubble (arr){ //bubble sort for computation
for (var i = 0; i < arr.length; i++) {
for (var j = 0; j < (arr.length - i - 1); j++) {
if (arr[j] > arr[j + 1]) {
var temp = arr[j]
arr[j] = arr[j + 1]
arr[j + 1] = temp
}
}
}
}
app.get("/", function rootHandler(req, res) {
var arr = Array.from({length: 400000}, () => Math.floor(Math.random() * 4000));
bubble(arr)
res.end("hiii")
});
Sentry.setupExpressErrorHandler(app);
app.listen(port, () => console.log(`Example app listening at http://localhost:${port}`))
Steps to Reproduce
- Run the app above
- Go to localhost:8000
Expected Result
The SDK sends profiles and transactions to the Sentry project.
Actual Result
Transactions are sent but no profiles. Here is the SDK debug log attached. Noticeably are the lines:
Sentry Logger [log]: [Profiling] started profiling transaction: GET
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for middleware - query: true
Sentry Logger [log]: [Tracing] Starting sampled span
....
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /
Sentry Logger [log]: Flushing outcomes...
Sentry Logger [log]: No outcomes to send
Sentry Logger [log]: [Profiling] max profile duration elapsed, stopping profiling for: GET /
Sentry Logger [log]: [Profiling] stopped profiling of transaction: GET /
Sentry Logger [log]: [Profiling] profiler returned null profile for: GET / this may indicate an overlapping span or a call to stopProfiling with a profile title that was never started
Sentry Logger [log]: Flushing client reports based on interval.
These are the same log messages reported by the affected customer, which had profiles sent by the SDK normally prior to the update from v7.120.0 to v8.42.0
Activity
Lms24 commentedon Dec 11, 2024
I believe @JonasBa mentioned recently that a root span needs to be active for a certain minimum amount of time (was it 20ms?) so that we can attach a profile. Any chance a too short root span is the problem?
amardesai1 commentedon Dec 11, 2024
Hi there. No most of our spans are 20-100ms
rodolfoBee commentedon Dec 11, 2024
My root span is 907ms as well.
This used to report profiles correctly on v7.120.0
3 remaining items
Lms24 commentedon Dec 12, 2024
Update: After some debugging, I think there are a couple of things that go wrong:
profileIdonto theprofilingcontext on the current scope on span start of the root span. For some reason this context isn't applied to the event. If I locally add it to the isolation scope instead, things work. So we could just generally put the profiling id onto the isolation scope. WDYT @@JonasBa?JonasBa commentedon Dec 12, 2024
@Lms24
Lms24 commentedon Dec 12, 2024
The duration is not the issue here. The txn lasts for over 2s in my repro and still the profile was not attached.
What I found in 1 is apparently an Otel instrumentation bug and is unrelated to profliling. This was already raised in the Otel repo and one of our contractors is gonna take a look at this.
Not within v8 but between v7 and v8, with the entire hub/scope refactoring a lot changed. I'm not entirely sure tbh why the current scope at root span start is not applied to the event but with OTEL forking scopes on every span start, I suspect this can happen somehow. This could have also happened with a recent otel instrumentation update. The root span has the expected duration though so I'm not sure.
I think for span-based profiling, it's fine to switch from the current to the isolation scope to set the profiling id as proposed in #14681.
For continuous profiling, the global scope makes sense intuitively. I'd suggest we leave it there as is for now?
Yup, out of the three things I noticed, this is the one I haven't looked at in too much detail.
Lms24 commentedon Dec 12, 2024
@amardesai1 @rodolfoBee I merged the PR that should restore profiles being sent. It will be released in the next days with the next SDK release. The "max profile duration elapsed" message might still appear but I think it shouldn't influence profile collection.
amardesai1 commentedon Dec 12, 2024
@Lms24 Thanks, could you please notify us when it's available? Then I can deploy it and see if we start seeing that profiling data.
Thanks!
Lms24 commentedon Dec 12, 2024
@amardesai1 You can subscribe to this PR which will trigger our release flow once it is merged: #14682
Also, you should receive an automatic reply on this issue once the release is published.
(I'm notoriously bad at informing folks about releases, sorry in advance if I'm not gonna notify you anymore)
github-actions commentedon Dec 13, 2024
A PR closing this issue has just been released 🚀
This issue was referenced by PR #14681, which was included in the 8.45.0 release.
amardesai1 commentedon Dec 13, 2024
@Lms24 Are the @sentry/profiling-node and @sentry/node packages available for update now?
Lms24 commentedon Dec 13, 2024
Yes :)
amardesai1 commentedon Dec 13, 2024
Hi @Lms24 I ran nom update on these two packages and there was no update available.
Thanks for your help
Lms24 commentedon Dec 16, 2024
If you run
npm install @sentry/node @sentry/profiling-nodeyou should get updates. Both packages have 8.45.0 as the latest version:amardesai1 commentedon Dec 17, 2024
@Lms24 Thanks! Resolved