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(apm): Heartbeat #2478

Merged
merged 7 commits into from
Mar 9, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 2 additions & 1 deletion CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,8 +4,9 @@

- "You miss 100 percent of the chances you don't take. — Wayne Gretzky" — Michael Scott

- [apm] feat: Add a simple heartbeat check, if activities don't change in 3 beats, finish the transaction (#2478)
- [apm] feat: Make use of the `performance` browser API to provide better instrumentation (#2474)
- [browser] ref: Move global error handler + unhandled promise rejection to instrument
- [browser] ref: Move global error handler + unhandled promise rejection to instrument (#2475)

## 5.13.2

Expand Down
178 changes: 129 additions & 49 deletions packages/apm/src/integrations/tracing.ts
Original file line number Diff line number Diff line change
Expand Up @@ -147,6 +147,12 @@ export class Tracing implements Integration {

private static _performanceCursor: number = 0;

private static _heartbeatTimer: number = 0;

private static _prevHeartbeatString: string | undefined;

private static _heartbeatCounter: number = 0;

/**
* Constructor for Tracing
*
Expand Down Expand Up @@ -200,27 +206,7 @@ export class Tracing implements Integration {
return;
}

if (Tracing.options.traceXHR) {
addInstrumentationHandler({
callback: xhrCallback,
type: 'xhr',
});
}

if (Tracing.options.traceFetch && supportsNativeFetch()) {
addInstrumentationHandler({
callback: fetchCallback,
type: 'fetch',
});
}

if (Tracing.options.startTransactionOnLocationChange) {
addInstrumentationHandler({
callback: historyCallback,
type: 'history',
});
}

// Starting our inital pageload transaction
if (global.location && global.location.href) {
// `${global.location.href}` will be used a temp transaction name
Tracing.startIdleTransaction(global.location.href, {
Expand All @@ -229,36 +215,17 @@ export class Tracing implements Integration {
});
}

/**
* If an error or unhandled promise occurs, we mark the active transaction as failed
*/
// tslint:disable-next-line: completed-docs
function errorCallback(): void {
if (Tracing._activeTransaction) {
logger.log(`[Tracing] Global error occured, setting status in transaction: ${SpanStatus.InternalError}`);
(Tracing._activeTransaction as SpanClass).setStatus(SpanStatus.InternalError);
}
}
this._setupXHRTracing();

addInstrumentationHandler({
callback: errorCallback,
type: 'error',
});
this._setupFetchTracing();

addInstrumentationHandler({
callback: errorCallback,
type: 'unhandledrejection',
});
this._setupHistory();

if (Tracing.options.discardBackgroundSpans && global.document) {
document.addEventListener('visibilitychange', () => {
if (document.hidden && Tracing._activeTransaction) {
logger.log('[Tracing] Discarded active transaction incl. activities since tab moved to the background');
Tracing._activeTransaction = undefined;
Tracing._activities = {};
}
});
}
this._setupErrorHandling();

this._setupBackgroundTabDetection();

Tracing._pingHeartbeat();

// This EventProcessor makes sure that the transaction is not longer than maxTransactionDuration
addGlobalEventProcessor((event: Event) => {
Expand All @@ -284,6 +251,119 @@ export class Tracing implements Integration {
});
}

/**
* Pings the heartbeat
*/
private static _pingHeartbeat(): void {
Tracing._heartbeatTimer = (setTimeout(() => {
Tracing._beat();
}, 5000) as any) as number;
}

/**
* Checks when entries of Tracing._activities are not changing for 3 beats. If this occurs we finish the transaction
*
*/
private static _beat(): void {
clearTimeout(Tracing._heartbeatTimer);
const keys = Object.keys(Tracing._activities);
if (keys.length) {
const heartbeatString = keys.reduce((prev: string, current: string) => prev + current);
Copy link
Contributor

Choose a reason for hiding this comment

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

Won't it be too fragile?

Copy link
Member Author

Choose a reason for hiding this comment

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

Not sure was looking for something reasonable of "hashing" this whole thing

Copy link
Contributor

Choose a reason for hiding this comment

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

Oooh, it's based on keys, so id, not type of activity. It shooooould be good enough for now then.

Copy link
Contributor

Choose a reason for hiding this comment

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

This can be unnecessarily large (it is a string of unbounded length). Plus it sort of relies on key order. Looking for something better...

Copy link
Contributor

Choose a reason for hiding this comment

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

Also, isn't this generating a lot of garbage for the GC every 5s?

Copy link
Contributor

Choose a reason for hiding this comment

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

if (heartbeatString === Tracing._prevHeartbeatString) {
Tracing._heartbeatCounter++;
} else {
Tracing._heartbeatCounter = 0;
}
if (Tracing._heartbeatCounter >= 3) {
if (Tracing._activeTransaction) {
logger.log(
"[Tracing] Heartbeat safeguard kicked in, finishing transaction since activities content hasn't changed for 3 beats",
);
Tracing._activeTransaction.setStatus(SpanStatus.DeadlineExceeded);
Copy link
Contributor

Choose a reason for hiding this comment

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

This status is the same as set by fromHttpCode for responses with 504 code.
Does it make sense to reuse the same status here?

Copy link
Contributor

Choose a reason for hiding this comment

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

Won't it be confusing the UI?

Copy link
Member Author

Choose a reason for hiding this comment

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

Hmm, you are not wrong but I thought we need to mark this transaction somehow and we also do it already for spans where autopop kicks in

Tracing._activeTransaction.setTag('heartbeat', 'failed');
Tracing.finishIdleTransaction();
}
}
Tracing._prevHeartbeatString = heartbeatString;
}
Tracing._pingHeartbeat();
}

/**
* Discards active transactions if tab moves to background
*/
private _setupBackgroundTabDetection(): void {
if (Tracing.options.discardBackgroundSpans && global.document) {
document.addEventListener('visibilitychange', () => {
if (document.hidden && Tracing._activeTransaction) {
logger.log('[Tracing] Discarded active transaction incl. activities since tab moved to the background');
Tracing._activeTransaction = undefined;
Tracing._activities = {};
}
});
}
}

/**
* Registers to History API to detect navigation changes
*/
private _setupHistory(): void {
if (Tracing.options.startTransactionOnLocationChange) {
addInstrumentationHandler({
callback: historyCallback,
type: 'history',
});
}
}

/**
* Attaches to fetch to add sentry-trace header + creating spans
*/
private _setupFetchTracing(): void {
if (Tracing.options.traceFetch && supportsNativeFetch()) {
addInstrumentationHandler({
callback: fetchCallback,
type: 'fetch',
});
}
}

/**
* Attaches to XHR to add sentry-trace header + creating spans
*/
private _setupXHRTracing(): void {
if (Tracing.options.traceXHR) {
addInstrumentationHandler({
callback: xhrCallback,
type: 'xhr',
});
}
}

/**
* Configures global error listeners
*/
private _setupErrorHandling(): void {
// tslint:disable-next-line: completed-docs
function errorCallback(): void {
if (Tracing._activeTransaction) {
/**
* If an error or unhandled promise occurs, we mark the active transaction as failed
*/
logger.log(`[Tracing] Global error occured, setting status in transaction: ${SpanStatus.InternalError}`);
(Tracing._activeTransaction as SpanClass).setStatus(SpanStatus.InternalError);
}
}
addInstrumentationHandler({
callback: errorCallback,
type: 'error',
});
addInstrumentationHandler({
callback: errorCallback,
type: 'unhandledrejection',
});
}

/**
* Is tracing enabled
*/
Expand Down Expand Up @@ -376,8 +456,8 @@ export class Tracing implements Integration {
public static finishIdleTransaction(): void {
const active = Tracing._activeTransaction as SpanClass;
if (active) {
logger.log('[Tracing] finishIdleTransaction', active.transaction);
Tracing._addPerformanceEntries(active);
logger.log('[Tracing] finishIdleTransaction', active.transaction);
Copy link
Contributor

Choose a reason for hiding this comment

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

Why is this moving down?

Copy link
Member Author

Choose a reason for hiding this comment

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

So debug prints are not confusing, that finish is the last thing we print before flushing the transaction.

Copy link
Contributor

Choose a reason for hiding this comment

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

👍

// true = use timestamp of last span
active.finish(true);
}
Expand Down