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

feat(tracing): Reset IdleTimeout based on activities count #4531

Merged
merged 15 commits into from
Mar 1, 2022

Conversation

AbhiPrasad
Copy link
Member

@AbhiPrasad AbhiPrasad commented Feb 9, 2022

Previously, when the activities count of an idle transaction hit 0, it would trigger a timeout for idleTimeout ms, and then always end the transaction. This means that if a span (like fetch/xhr request) started right after the activities count went to 0 (1 -> 0 -> 1), the transaction would always finish after idleTimeout ms, instead of waiting for the newest activity to finish.

This was primarily done to prevent polling conditions and to not artificially inflate duration. Nowadays though, web vitals like LCP are a lot more important as a measurement in transactions than the strict duration (as with activities, they are a bit arbitrary). By making idleTimeout be strict about finish after activities go to 0, we often times would miss the LCP value that the browser would record, leading to many transactions not having proper LCPs.

To get the LCP value close to browser quality as possible, we now reset the idleTimeout timeout if there are still existing activities. The concern here is with polling. To prevent polling issues, we now also have an additional finalTimeout that is started when the idle transaction is created. This double timeout system (alongside the heartbeat), should always enforce that the transaction is finished.

To test out these new options, we are cutting a beta to test on getsentry/sentry first, and then we will think about how to do a full release with this.

An image explanation (opt-in)

Sorry for adding bytes tracing bundle 😢

@github-actions
Copy link
Contributor

github-actions bot commented Feb 9, 2022

size-limit report

Path Base Size (e0ca11e) Current Size Change
@sentry/browser - ES5 CDN Bundle (gzipped + minified) 19.77 KB 19.77 KB 0%
@sentry/browser - ES5 CDN Bundle (minified) 63.47 KB 63.47 KB 0%
@sentry/browser - ES6 CDN Bundle (gzipped + minified) 18.44 KB 18.44 KB +0.03% 🔺
@sentry/browser - ES6 CDN Bundle (minified) 56.6 KB 56.6 KB 0%
@sentry/browser - Webpack (gzipped + minified) 22.2 KB 22.2 KB 0%
@sentry/browser - Webpack (minified) 76.36 KB 76.36 KB 0%
@sentry/react - Webpack (gzipped + minified) 22.23 KB 22.23 KB 0%
@sentry/nextjs Client - Webpack (gzipped + minified) 46.4 KB 46.52 KB +0.27% 🔺
@sentry/browser + @sentry/tracing - ES5 CDN Bundle (gzipped + minified) 27.22 KB 27.33 KB +0.4% 🔺

@lobsterkatie
Copy link
Member

Sorry for adding bytes tracing bundle 😢

It's okay - I just lowered it 4%, so we're still ahead. 😛

Copy link
Member

@lobsterkatie lobsterkatie left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A few comments, but overall looks good! (I actually didn't realize we don't already do this.)

* Time is in ms.
*
* Default: 1000
*/
idleTimeout: number;

/**
* The max transaction duration for a transaction. If a transaction duration hits the `finalTimeout` value, it
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
* The max transaction duration for a transaction. If a transaction duration hits the `finalTimeout` value, it
* The max duration for a transaction. If a transaction duration hits the `finalTimeout` value, it

packages/tracing/src/idletransaction.ts Outdated Show resolved Hide resolved
@@ -96,11 +111,13 @@ export class IdleTransaction extends Transaction {
_idleHub.configureScope(scope => scope.setSpan(this));
}

this._initTimeout = setTimeout(() => {
this._startIdleTimeout();
global.setTimeout(() => {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this need to be called on global?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It makes it less likely to fail in the future - so I set it this way.

packages/tracing/src/idletransaction.ts Outdated Show resolved Hide resolved
packages/tracing/src/idletransaction.ts Outdated Show resolved Hide resolved
/**
* Creates an idletimeout
*/
private _startIdleTimeout(end?: Parameters<IdleTransaction['finish']>[0]): void {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When using Parameters, I think it's helpful to give the variable the same name as the parameter in question. (Also, renaming this makes it clearer what it actually is.)

Suggested change
private _startIdleTimeout(end?: Parameters<IdleTransaction['finish']>[0]): void {
private _startIdleTimeout(endTimestamp?: Parameters<IdleTransaction['finish']>[0]): void {

this._idleTimeoutID = global.setTimeout(() => {
if (!this._finished && Object.keys(this.activities).length === 0) {
this.setTag(FINISH_REASON_TAG, IDLE_TRANSACTION_FINISH_REASONS[1]);
this.finish(end);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
this.finish(end);
this.finish(endTimestamp);

this.finish(end);
}
}, timeout);
this._startIdleTimeout(end);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
this._startIdleTimeout(end);
this._startIdleTimeout(endTimestamp);

(It won't let me fix the line above, because it hasn't been changed, but there, too.)

packages/tracing/test/idletransaction.test.ts Show resolved Hide resolved
* Creates an idletimeout
*/
private _startIdleTimeout(end?: Parameters<IdleTransaction['finish']>[0]): void {
this._cancelIdleTimeout();

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

'heartbeatFailed',
'idleTimeout',
'documentHidden',
'finalTimeout',
Copy link
Contributor

@snoozbuster snoozbuster Feb 12, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

given that this shows up in the UI, and I as a user of sentry would probably not understand what this means if I hadn't already found this issue and read this PR, does it make more sense to name this something that indicates it's a forced timeout due to thrashing? hard to come up with a concise name but maybe something like thrashedSpanTimeout or timeoutInfinitePoll? (idleTimeout was a similarly confusing name to me, it's not obvious that's the sort of "intended finish reason" for normal transactions, but realize that probably can't be changed anymore)

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch.

Its behaviour seems like as the maxTransactionDuration configuration.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

does it make sense to re-use that configuration option here then (as opposed to creating a new one), and similarly re-use the "deadline_exceeded" finishReason? or is there value in having them both be separate? I guess a default timeout of 600 seconds is pretty excessive for this particular use case...

@AbhiPrasad
Copy link
Member Author

@snoozbuster @alquerci thanks for the comments. We're running some tests off a beta on the Sentry frontend right now (getsentry/sentry#31761), and once we've got that data, I'll come back and formally reply to the review comments.

We'll also share the data here - and give y'all an opportunity to give feedback. Appreciate the patience!

AbhiPrasad added a commit that referenced this pull request Mar 1, 2022
This branch tracks the beta for `6.18.1-beta.0`. For more information see: #4531.

Prev beta: #4554
AbhiPrasad added a commit that referenced this pull request Mar 1, 2022
This branch tracks the beta for `6.18.1-beta.0`. For more information see: #4531.

Prev beta: #4554
AbhiPrasad added a commit that referenced this pull request Mar 1, 2022
This branch tracks the beta for `6.18.1-beta.0`. For more information see: #4531.

Prev beta: #4554
AbhiPrasad added a commit that referenced this pull request Mar 1, 2022
This branch tracks the beta for `6.18.1-beta.0`. For more information see: #4531.

Prev beta: #4554
AbhiPrasad added a commit that referenced this pull request Mar 1, 2022
This branch tracks the beta for `6.18.1-beta.0`. For more information see: #4531.

Prev beta: #4554
@getsentry-bot getsentry-bot merged commit a7cbb92 into master Mar 1, 2022
@getsentry-bot getsentry-bot deleted the abhi-reset-idletimeout branch March 1, 2022 20:08
@AbhiPrasad AbhiPrasad restored the abhi-reset-idletimeout branch March 1, 2022 20:24
@AbhiPrasad
Copy link
Member Author

Uhh that wasn't supposed to happen

We are close to shipping this though.

AbhiPrasad added a commit to getsentry/sentry that referenced this pull request Mar 1, 2022
AbhiPrasad added a commit to getsentry/sentry that referenced this pull request Mar 1, 2022
AbhiPrasad added a commit that referenced this pull request Mar 2, 2022
This branch tracks the beta for `6.18.1-beta.0`. For more information see: #4531.

Prev beta: #4554
@simenbrekken-visma
Copy link

I can't locate these changes in master even though the PR says they've been merged. Is there another 6.x release I can use or should I go directly to 7.x for this?

@AbhiPrasad
Copy link
Member Author

These changes are part of the latest 7.x beta!

@simenbrekken-visma
Copy link

I just switched to the 7.x branch and my staggered activities problems immediately disappeared. Thanks and great work!

@AbhiPrasad AbhiPrasad deleted the abhi-reset-idletimeout branch May 30, 2022 13:25
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants