Skip to content

Commit

Permalink
fix: Server Timing - Remove reliance on performance API (#930)
Browse files Browse the repository at this point in the history
  • Loading branch information
@patrickhousley
patrickhousley authored Mar 26, 2024
1 parent 7a1ba34 commit 250efcd
Show file tree
Hide file tree
Showing 3 changed files with 32 additions and 154 deletions.
32 changes: 13 additions & 19 deletions src/common/timing/time-keeper.js
View file
Original file line number Diff line number Diff line change
@@ -1,5 +1,4 @@
import { gosNREUM } from '../window/nreum'
import { globalScope } from '../constants/runtime'
import { getRuntime } from '../config/config'

/**
Expand Down Expand Up @@ -41,30 +40,17 @@ export class TimeKeeper {
/**
* Process a rum request to calculate NR server time.
* @param rumRequest {XMLHttpRequest} The xhr for the rum request
* @param rumRequestUrl {string} The full url of the rum request
* @param startTime {number} The start time of the RUM request
* @param endTime {number} The end time of the RUM request
*/
processRumRequest (rumRequest, rumRequestUrl) {
processRumRequest (rumRequest, startTime, endTime) {
const responseDateHeader = rumRequest.getResponseHeader('Date')
if (!responseDateHeader) {
throw new Error('Missing date header on rum response.')
}

const resourceEntries = globalScope.performance.getEntriesByName(rumRequestUrl, 'resource')
if (!Array.isArray((resourceEntries)) || resourceEntries.length === 0) {
throw new Error('Missing rum request performance entry.')
}

let medianRumOffset = 0
let serverOffset = 0
if (typeof resourceEntries[0].responseStart === 'number' && resourceEntries[0].responseStart !== 0) {
// Cors is enabled and we can make a more accurate calculation of NR server time
medianRumOffset = (resourceEntries[0].responseStart - resourceEntries[0].requestStart) / 2
serverOffset = Math.floor(resourceEntries[0].requestStart + medianRumOffset)
} else {
// Cors is disabled or erred, we need to use a less accurate calculation
medianRumOffset = (resourceEntries[0].responseEnd - resourceEntries[0].fetchStart) / 2
serverOffset = Math.floor(resourceEntries[0].fetchStart + medianRumOffset)
}
const medianRumOffset = (endTime - startTime) / 2
const serverOffset = Math.floor(startTime + medianRumOffset)

// Corrected page origin time
this.#correctedOriginTime = Math.floor(Date.parse(responseDateHeader) - serverOffset)
Expand Down Expand Up @@ -93,4 +79,12 @@ export class TimeKeeper {
correctAbsoluteTimestamp (timestamp) {
return Math.floor(timestamp - this.#localTimeDiff)
}

/**
* Returns the current time offset from page origin.
* @return {number}
*/
now () {
return Math.floor(performance.now())
}
}
147 changes: 14 additions & 133 deletions src/common/timing/time-keeper.test.js
View file
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
import { faker } from '@faker-js/faker'
import { globalScope } from '../constants/runtime'
import { TimeKeeper } from './time-keeper'
import * as configModule from '../config/config'

jest.enableAutomock()
jest.unmock('./time-keeper')

const startTime = 450
const endTime = 600

let localTime
let serverTime
let mockAgent
Expand Down Expand Up @@ -37,15 +39,7 @@ describe('processRumRequest', () => {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl)
timeKeeper.processRumRequest(mockRumRequest, startTime, endTime)

expect(timeKeeper.correctedPageOriginTime).toEqual(1706213060475)
})
Expand All @@ -57,15 +51,7 @@ describe('processRumRequest', () => {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl)
timeKeeper.processRumRequest(mockRumRequest, startTime, endTime)

expect(timeKeeper.correctedPageOriginTime).toEqual(1706213055475)
})
Expand All @@ -75,24 +61,13 @@ describe('processRumRequest', () => {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart,
responseEnd: 600,
fetchStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl)
timeKeeper.processRumRequest(mockRumRequest, startTime, endTime)

expect(timeKeeper.correctedPageOriginTime).toEqual(1706213060475)
})

it.each([null, undefined])('should throw an error when rumRequest is %s', (rumRequest) => {
const rumRequestUrl = faker.internet.url()

expect(() => timeKeeper.processRumRequest(rumRequest, rumRequestUrl))
expect(() => timeKeeper.processRumRequest(rumRequest, startTime, endTime))
.toThrowError()
})

Expand All @@ -101,15 +76,7 @@ describe('processRumRequest', () => {
getResponseHeader: jest.fn(() => dateHeader)
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

expect(() => timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl))
expect(() => timeKeeper.processRumRequest(mockRumRequest, startTime, endTime))
.toThrowError()
})

Expand All @@ -118,53 +85,7 @@ describe('processRumRequest', () => {
getResponseHeader: jest.fn(() => { throw new Error('test error') })
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

expect(() => timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl))
.toThrowError()
})

it('should throw an error when getEntriesByName throws error', () => {
const mockRumRequest = {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
globalScope.performance.getEntriesByName = jest.fn(() => { throw new Error('test error') })

const timeKeeper = new TimeKeeper(mockAgent)

expect(() => timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl))
.toThrowError()
})

it.each([null, undefined, {}])('should throw an error when getEntriesByName returns %s instead of an array', (performanceEntries) => {
const mockRumRequest = {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
globalScope.performance.getEntriesByName = jest.fn(() => performanceEntries)

expect(() => timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl))
.toThrowError()
})

it('should throw an error when getEntriesByName returns an empty array', () => {
const mockRumRequest = {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
globalScope.performance.getEntriesByName = jest.fn(() => [])

expect(() => timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl))
expect(() => timeKeeper.processRumRequest(mockRumRequest, startTime, endTime))
.toThrowError()
})

Expand All @@ -173,15 +94,7 @@ describe('processRumRequest', () => {
getResponseHeader: jest.fn(() => serverTime)
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

expect(() => timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl))
expect(() => timeKeeper.processRumRequest(mockRumRequest, startTime, endTime))
.toThrowError()
})
})
Expand All @@ -192,15 +105,7 @@ describe('corrected time calculations', () => {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl)
timeKeeper.processRumRequest(mockRumRequest, startTime, endTime)

const relativeTimeA = 225
const correctedRelativeTimeA = timeKeeper.convertRelativeTimestamp(relativeTimeA)
Expand All @@ -218,15 +123,7 @@ describe('corrected time calculations', () => {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl)
timeKeeper.processRumRequest(mockRumRequest, startTime, endTime)

const relativeTimeA = 225
const correctedRelativeTimeA = timeKeeper.convertRelativeTimestamp(relativeTimeA)
Expand All @@ -242,15 +139,7 @@ describe('corrected time calculations', () => {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl)
timeKeeper.processRumRequest(mockRumRequest, startTime, endTime)

const absoluteTimeA = 1706213058225
const correctedAbsoluteTimeA = timeKeeper.correctAbsoluteTimestamp(absoluteTimeA)
Expand All @@ -268,15 +157,7 @@ describe('corrected time calculations', () => {
getResponseHeader: jest.fn(() => (new Date(serverTime)).toUTCString())
}

const rumRequestUrl = faker.internet.url()
const rumRequestPerformanceEntry = {
name: rumRequestUrl,
responseStart: 600,
requestStart: 450
}
globalScope.performance.getEntriesByName = jest.fn(() => [rumRequestPerformanceEntry])

timeKeeper.processRumRequest(mockRumRequest, rumRequestUrl)
timeKeeper.processRumRequest(mockRumRequest, startTime, endTime)

const absoluteTimeA = 1706213058225
const correctedAbsoluteTimeA = timeKeeper.correctAbsoluteTimestamp(absoluteTimeA)
Expand Down
7 changes: 5 additions & 2 deletions src/features/page_view_event/aggregate/index.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -100,19 +100,22 @@ export class Aggregate extends AggregateBase {
queryParameters.fp = firstPaint.current.value
queryParameters.fcp = firstContentfulPaint.current.value

const rumStartTime = this.timeKeeper.now()
harvester.send({
endpoint: 'rum',
payload: { qs: queryParameters, body },
opts: { needResponse: true, sendEmptyBody: true },
cbFinished: ({ status, responseText, xhr, fullUrl }) => {
cbFinished: ({ status, responseText, xhr }) => {
const rumEndTime = this.timeKeeper.now()

if (status >= 400 || status === 0) {
// Adding retry logic for the rum call will be a separate change
this.ee.abort()
return
}

try {
this.timeKeeper.processRumRequest(xhr, fullUrl)
this.timeKeeper.processRumRequest(xhr, rumStartTime, rumEndTime)
} catch (error) {
handle(SUPPORTABILITY_METRIC_CHANNEL, ['PVE/NRTime/Calculation/Failed'], undefined, FEATURE_NAMES.metrics, this.ee)
drain(this.agentIdentifier, FEATURE_NAMES.metrics, true)
Expand Down

0 comments on commit 250efcd

Please sign in to comment.