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

Wrap all heartbeats methods in try/catch #8425

Merged
merged 2 commits into from
Aug 14, 2024
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
5 changes: 5 additions & 0 deletions .changeset/large-games-dress.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
---
'@firebase/app': patch
---

Prevent heartbeats methods from throwing - warn instead.
20 changes: 20 additions & 0 deletions packages/app/src/heartbeatService.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -146,6 +146,26 @@ describe('HeartbeatServiceImpl', () => {
const emptyHeaders = await heartbeatService.getHeartbeatsHeader();
expect(emptyHeaders).to.equal('');
});
it(`triggerHeartbeat() doesn't throw even if code errors`, async () => {
//@ts-expect-error Ensure this doesn't match
heartbeatService._heartbeatsCache?.lastSentHeartbeatDate = 50;
//@ts-expect-error Ensure you can't .push() to this
heartbeatService._heartbeatsCache.heartbeats = 50;
const warnStub = stub(console, 'warn');
await heartbeatService.triggerHeartbeat();
expect(warnStub).to.be.called;
expect(warnStub.args[0][1].message).to.include('heartbeats');
warnStub.restore();
});
it(`getHeartbeatsHeader() doesn't throw even if code errors`, async () => {
//@ts-expect-error Ensure you can't .push() to this
heartbeatService._heartbeatsCache.heartbeats = 50;
const warnStub = stub(console, 'warn');
await heartbeatService.getHeartbeatsHeader();
expect(warnStub).to.be.called;
expect(warnStub.args[0][1].message).to.include('heartbeats');
warnStub.restore();
});
});
describe('If IndexedDB has entries', () => {
let heartbeatService: HeartbeatServiceImpl;
Expand Down
136 changes: 73 additions & 63 deletions packages/app/src/heartbeatService.ts
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ import {
HeartbeatStorage,
SingleDateHeartbeat
} from './types';
import { logger } from './logger';

const MAX_HEADER_BYTES = 1024;
// 30 days
Expand Down Expand Up @@ -80,43 +81,47 @@ export class HeartbeatServiceImpl implements HeartbeatService {
* already logged, subsequent calls to this function in the same day will be ignored.
*/
async triggerHeartbeat(): Promise<void> {
const platformLogger = this.container
.getProvider('platform-logger')
.getImmediate();
try {
const platformLogger = this.container
.getProvider('platform-logger')
.getImmediate();

// This is the "Firebase user agent" string from the platform logger
// service, not the browser user agent.
const agent = platformLogger.getPlatformInfoString();
const date = getUTCDateString();
if (this._heartbeatsCache?.heartbeats == null) {
this._heartbeatsCache = await this._heartbeatsCachePromise;
// If we failed to construct a heartbeats cache, then return immediately.
// This is the "Firebase user agent" string from the platform logger
// service, not the browser user agent.
const agent = platformLogger.getPlatformInfoString();
const date = getUTCDateString();
console.log('heartbeats', this._heartbeatsCache?.heartbeats);

Choose a reason for hiding this comment

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

Is this intentional or an oversight?

Copy link

@robertIsaac robertIsaac Aug 18, 2024

Choose a reason for hiding this comment

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

hi @hsubox76
this is showing in our production logs now, can you please remove it
it took me a while to see where is it coming from
I updated many dependencies and wasn't sure which one caused these logs

Copy link

Choose a reason for hiding this comment

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

After updating Firebase to version 10.13.0, I'm seeing a console log message that says heartbeats undefined. It would be great if the log could be removed!

Copy link

Choose a reason for hiding this comment

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

Same here

Copy link

@gustavopch gustavopch Aug 26, 2024

Choose a reason for hiding this comment

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

I can't update to 10.13.0 because of this as it adds a lot of noise to my frontend monitoring logs.

EDIT: they'll release a fix soon: #8436 (comment)

Copy link
Contributor

Choose a reason for hiding this comment

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

@GogoVega @robertIsaac @Tosters @BenaymS @gustavopch

This was removed in 10.13.1

if (this._heartbeatsCache?.heartbeats == null) {
this._heartbeatsCache = await this._heartbeatsCachePromise;
// If we failed to construct a heartbeats cache, then return immediately.
if (this._heartbeatsCache?.heartbeats == null) {
return;
}
}
// Do not store a heartbeat if one is already stored for this day
// or if a header has already been sent today.
if (
this._heartbeatsCache.lastSentHeartbeatDate === date ||
this._heartbeatsCache.heartbeats.some(
singleDateHeartbeat => singleDateHeartbeat.date === date
)
) {
return;
} else {
// There is no entry for this date. Create one.
this._heartbeatsCache.heartbeats.push({ date, agent });
}
// Remove entries older than 30 days.
this._heartbeatsCache.heartbeats =
this._heartbeatsCache.heartbeats.filter(singleDateHeartbeat => {
const hbTimestamp = new Date(singleDateHeartbeat.date).valueOf();
const now = Date.now();
return now - hbTimestamp <= STORED_HEARTBEAT_RETENTION_MAX_MILLIS;
});
return this._storage.overwrite(this._heartbeatsCache);
} catch (e) {
logger.warn(e);
}
// Do not store a heartbeat if one is already stored for this day
// or if a header has already been sent today.
if (
this._heartbeatsCache.lastSentHeartbeatDate === date ||
this._heartbeatsCache.heartbeats.some(
singleDateHeartbeat => singleDateHeartbeat.date === date
)
) {
return;
} else {
// There is no entry for this date. Create one.
this._heartbeatsCache.heartbeats.push({ date, agent });
}
// Remove entries older than 30 days.
this._heartbeatsCache.heartbeats = this._heartbeatsCache.heartbeats.filter(
singleDateHeartbeat => {
const hbTimestamp = new Date(singleDateHeartbeat.date).valueOf();
const now = Date.now();
return now - hbTimestamp <= STORED_HEARTBEAT_RETENTION_MAX_MILLIS;
}
);
return this._storage.overwrite(this._heartbeatsCache);
}

/**
Expand All @@ -127,39 +132,44 @@ export class HeartbeatServiceImpl implements HeartbeatService {
* returns an empty string.
*/
async getHeartbeatsHeader(): Promise<string> {
if (this._heartbeatsCache === null) {
await this._heartbeatsCachePromise;
}
// If it's still null or the array is empty, there is no data to send.
if (
this._heartbeatsCache?.heartbeats == null ||
this._heartbeatsCache.heartbeats.length === 0
) {
try {
if (this._heartbeatsCache === null) {
await this._heartbeatsCachePromise;
}
// If it's still null or the array is empty, there is no data to send.
if (
this._heartbeatsCache?.heartbeats == null ||
this._heartbeatsCache.heartbeats.length === 0
) {
return '';
}
const date = getUTCDateString();
// Extract as many heartbeats from the cache as will fit under the size limit.
const { heartbeatsToSend, unsentEntries } = extractHeartbeatsForHeader(
this._heartbeatsCache.heartbeats
);
const headerString = base64urlEncodeWithoutPadding(
JSON.stringify({ version: 2, heartbeats: heartbeatsToSend })
);
// Store last sent date to prevent another being logged/sent for the same day.
this._heartbeatsCache.lastSentHeartbeatDate = date;
if (unsentEntries.length > 0) {
// Store any unsent entries if they exist.
this._heartbeatsCache.heartbeats = unsentEntries;
// This seems more likely than emptying the array (below) to lead to some odd state
// since the cache isn't empty and this will be called again on the next request,
// and is probably safest if we await it.
await this._storage.overwrite(this._heartbeatsCache);
} else {
this._heartbeatsCache.heartbeats = [];
// Do not wait for this, to reduce latency.
void this._storage.overwrite(this._heartbeatsCache);
}
return headerString;
} catch (e) {
logger.warn(e);
return '';
}
const date = getUTCDateString();
// Extract as many heartbeats from the cache as will fit under the size limit.
const { heartbeatsToSend, unsentEntries } = extractHeartbeatsForHeader(
this._heartbeatsCache.heartbeats
);
const headerString = base64urlEncodeWithoutPadding(
JSON.stringify({ version: 2, heartbeats: heartbeatsToSend })
);
// Store last sent date to prevent another being logged/sent for the same day.
this._heartbeatsCache.lastSentHeartbeatDate = date;
if (unsentEntries.length > 0) {
// Store any unsent entries if they exist.
this._heartbeatsCache.heartbeats = unsentEntries;
// This seems more likely than emptying the array (below) to lead to some odd state
// since the cache isn't empty and this will be called again on the next request,
// and is probably safest if we await it.
await this._storage.overwrite(this._heartbeatsCache);
} else {
this._heartbeatsCache.heartbeats = [];
// Do not wait for this, to reduce latency.
void this._storage.overwrite(this._heartbeatsCache);
}
return headerString;
}
}

Expand Down
Loading