Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Some errors are not reported to sentry #1491

Closed
danielbeardsley opened this issue Mar 21, 2023 · 16 comments
Closed

Some errors are not reported to sentry #1491

danielbeardsley opened this issue Mar 21, 2023 · 16 comments
Assignees
Labels
0 bug Something isn't working research

Comments

@danielbeardsley
Copy link
Member

danielbeardsley commented Mar 21, 2023

Some errors like those below aren't being repoted to sentry.

START RequestId: 30b245bf-3743-46ee-85fa-8e1369d37e5f Version: $LATEST
2023-03-21T09:31:16.944Z	undefined	INFO	info  - Loaded env from /var/task/frontend/.env.production
2023-03-21T09:31:21.518Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	context.resolvedUrl /Parts/MacBook_Pro/Display_Components?p=-1%20OR%203%2B947-947-1%3D0%2B0%2B0%2B1
2023-03-21T09:31:21.518Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	context.req.url /Parts/MacBook_Pro/Display_Components?p=-1%20OR%203%2B947-947-1%3D0%2B0%2B0%2B1
2023-03-21T09:31:21.566Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	iFixit API GET:cart/part_collections/devices/MacBook_Pro => 26.58ms
2023-03-21T09:31:21.576Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	Cache miss for 'storeList' => 50.20ms
2023-03-21T09:31:21.579Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	Cache miss for 'globalSettings' => 60.11ms
2023-03-21T09:31:21.604Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	strapi.getProductList => 66.13ms
2023-03-21T09:31:21.622Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	algolia.findDescendantDevicesWithProducts => 14.38ms
2023-03-21T09:31:21.622Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	findProductList => 84.63ms
2023-03-21T09:31:22.217Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	Cache miss for 'store-us' => 689.23ms
2023-03-21T09:31:22.217Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	INFO	layoutProps => 698.39ms
2023-03-21T09:31:22.520Z	30b245bf-3743-46ee-85fa-8e1369d37e5f	ERROR	Unhandled Promise Rejection 	{"errorType":"Runtime.UnhandledPromiseRejection","errorMessage":"ApiError: Value too small for \"page\" parameter, expected integer between 0 and 9223372036854775807","trace":["Runtime.UnhandledPromiseRejection: ApiError: Value too small for \"page\" parameter, expected integer between 0 and 9223372036854775807","    at process.<anonymous> (file:///var/runtime/index.mjs:1188:17)","    at process.emit (node:events:525:35)","    at process.emit (node:domain:489:12)","    at emit (node:internal/process/promises:140:20)","    at processPromiseRejections (node:internal/process/promises:274:27)","    at processTicksAndRejections (node:internal/process/task_queues:97:32)"]}
Unknown application error occurred
Runtime.Unknown
END RequestId: 30b245bf-3743-46ee-85fa-8e1369d37e5f
REPORT RequestId: 30b245bf-3743-46ee-85fa-8e1369d37e5f	Duration: 6171.92 ms	Billed Duration: 6172 ms	Memory Size: 1024 MB	Max Memory Used: 203 MB

Bad url params resulted in a 500 (#1492 -- issue to fix that bug), but it wasn't reported to sentry. What else are we missing?

Do This

Ensure all errors are reported to sentry.

@sterlinghirsh sterlinghirsh added 0 bug Something isn't working research labels Mar 21, 2023
@sterlinghirsh
Copy link
Member

Take another look at Sentry nextjs integration. See if we can use the default integration/configuration.

@masonmcelvain masonmcelvain self-assigned this Mar 21, 2023
@masonmcelvain
Copy link
Contributor

@danielbeardsley
Copy link
Member Author

While in production, it does generate an error, but doesn't get captured by sentry:
image

@masonmcelvain
Copy link
Contributor

That means this issue only happens on Vercel. I turned on debug logging when we initialize sentry with

Sentry.init({
   debug: true,
   ...
});

and it gave a hint:

[@sentry/nextjs] You are using Next.js features that run on the Edge Runtime.
Please add a "sentry.edge.config.js" or a "sentry.edge.config.ts" file to your
project root in which you initialize the Sentry SDK with "Sentry.init()".

I don't think edge.config was available when we first installed Sentry. Pull incoming!

@sterlinghirsh
Copy link
Member

sterlinghirsh commented Mar 21, 2023

FYI I've also seen this when an invalid Algolia filter is specified in a ProductList. #1399

@masonmcelvain
Copy link
Contributor

Nice find. Yea I think any invalid algolia param has the potential to tank the app

return {
q: String(q || ''),
p: typeof p === 'string' ? parseInt(p) : undefined,
filter: filterObject,
};

@masonmcelvain
Copy link
Contributor

This seems very similar to our case, where errors in getServerSideProps aren't being reported on Vercel: getsentry/sentry-javascript#6117

@masonmcelvain
Copy link
Contributor

Made an issue on sentry's repo: getsentry/sentry-javascript#7602

@danielbeardsley's hunch was right, the errors are reported on Vercel for synchronous errors, but not async ones.

@jarstelfox
Copy link
Contributor

FYI we do our best to handle this ourselves in PHP:

We wrap all sentry integration logic with a try-catch:
https://github.com/iFixit/ifixit/blob/735954fdb38b70b27e062d77c29a1f251775e29d/iFixit/Framework/Errors/SentryReporter.php#L113-L120

If we get an error while trying to report an error. We push the new error into the same sentry event:
https://github.com/iFixit/ifixit/blob/735954fdb38b70b27e062d77c29a1f251775e29d/iFixit/Framework/Errors/SentryReporter.php#L296-L307

In case it is unclear: Sentry allows more than one error per single send. Here is an example.

@masonmcelvain masonmcelvain removed their assignment Apr 7, 2023
@masonmcelvain
Copy link
Contributor

After a bit of experimentation (#1504, #1522), I'm loosing hope that we can do anything in our app code to catch unhandled promise rejections before vercel terminates the process. Hopefully the Sentry team takes this on soon, since it affects everyone using Next.js data fetching methods on Vercel (getsentry/sentry-javascript#7602).

@danielbeardsley danielbeardsley self-assigned this Apr 7, 2023
@danielbeardsley
Copy link
Member Author

I'm gonna play with this a bit.

@danielbeardsley
Copy link
Member Author

danielbeardsley commented Apr 7, 2023

Oh boy... I had always wondered how they possibly could capture scope in an async environment... but it turns out they ..... don't. There's a lot going on in this thread: getsentry/sentry-javascript#4071 with lots of ideas, discussions, experimentation, ... but it's not a solved problem (issue has been open for years).

Update:
It seems they say they have it solved (mostly) in the next.js integration:

If each request is isolated to it's own domain, it should get a unique hub, which means that we isolate scope/transactions/breadcrumbs correctly. We do this out of the box for our express, nextjs, and remix integrations. -- From a comment

@danielbeardsley
Copy link
Member Author

I've done more experimentation and can say that yes vercel terminates the next.js process (or at least the request) immediately and our rejection handler never runs.

I've opened a case with vercel:

Your case has been opened and your case number is 00134177. One of our Customer Success Engineers will be in touch to help you soon. The current expected response time for a case submitted under a Vercel Pro account is 2-4 business days

I see this message at the end of the logs when an unhandled rejection happens:

Cache miss for 'store-us' => 215.65ms
layoutProps => 234.58ms
strapi.getProductList => 225.25ms
Unhandled Promise Rejection 	{"errorType":"Runtime.UnhandledPromiseRejection","errorMessage":"I'm a bad promise","reason":"I'm a bad promise","promise":{},"stack":["Runtime.UnhandledPromiseRejection: I'm a bad promise","    at process.<anonymous> (file:///var/runtime/index.mjs:1189:17)","    at process.emit (node:events:525:35)","    at process.emit (node:domain:489:12)","    at emit (node:internal/process/promises:140:20)","    at processPromiseRejections (node:internal/process/promises:274:27)","    at processTicksAndRejections (node:internal/process/task_queues:97:32)"]}
Unknown application error occurred
Runtime.Unknown

Generated by this branch

@danielbeardsley
Copy link
Member Author

2 weeks later Vercel gets back to me and doesn't even read the content of my short message to them. This is there reply (from a "Senior Customer success engineer").

In the case of functions timing out, consider this example on how to handle it:
https://vercel.com/guides/what-can-i-do-about-vercel-serverless-functions-timing-out

You can see the live logs when making a request from your Logs tab:
[screenshot of the logs tab]

Sooo... I don't have much hope that they'll actually respond nor even address the problem...

@danielbeardsley
Copy link
Member Author

I've created a data-dog "monitor" to watch for error logs: https://app.datadoghq.com/monitors/119860918

This should alert us if we get these type of errors (that aren't reported to Sentry)

@danielbeardsley
Copy link
Member Author

Go figure... vercel responded with:

Hi there,
This case has been escalated for our engineer to look into. We'll update you once we hear back.
Thanks for your patience!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
0 bug Something isn't working research
Projects
None yet
4 participants