Skip to content

Commit

Permalink
fix: report LCP score properly (#1190)
Browse files Browse the repository at this point in the history
* fix: handle lcp entries corresponding to pictorial elements

* chore: fix wrong unit test

* chore: monitor browser events in page-load delay

* chore: test page load delay is being set

* chore: adapt e2e tests to page-load delay

* chore: adapt e2e tests to page-load delay

* chore: remove constant leftover

* chore: adapt react e2e

* chore: improve e2e implementation

* chore: adapt vue e2e test

* chore: adapt angular e2e test

* chore: overcome karma issue with longtask

* chore: improve test readability

* chore: move constant to rum-core

* chore: rename apm server mock

* chore: take domComplete into account

* chore: subtract delay from transaction end time
  • Loading branch information
devcorpio authored Apr 20, 2022
1 parent 7dba7cf commit 9ff2dd0
Show file tree
Hide file tree
Showing 19 changed files with 281 additions and 99 deletions.
6 changes: 4 additions & 2 deletions dev-utils/webdriver.js
Original file line number Diff line number Diff line change
Expand Up @@ -247,7 +247,7 @@ function isPageLoaded() {
})
}

function waitForApmServerCalls(errorCount = 0, transactionCount = 0) {
function getLastServerCall(errorCount = 0, transactionCount = 0) {
const { name = '', version = '' } = getBrowserInfo()
console.log(
`Waiting for minimum ${errorCount} Errors and ${transactionCount} Transactions in`,
Expand Down Expand Up @@ -302,11 +302,13 @@ function waitForApmServerCalls(errorCount = 0, transactionCount = 0) {
errors: errors
}
}
apmServerMock.resetMock()
done(calls)
}
})
.catch(function (reason) {
console.log('reason', JSON.stringify(reason))
apmServerMock.resetMock()
try {
done({ error: reason.message || JSON.stringify(reason) })
} catch (e) {
Expand Down Expand Up @@ -371,7 +373,7 @@ module.exports = {
isChromeLatest,
getWebdriveBaseConfig,
getBrowserInfo,
waitForApmServerCalls,
getLastServerCall,
getBrowserFeatures,
isPageLoaded
}
20 changes: 10 additions & 10 deletions packages/rum-angular/test/e2e/with-router/app.e2e-spec.js
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@
*
*/

const { waitForApmServerCalls } = require('../../../../../dev-utils/webdriver')
const { getLastServerCall } = require('../../../../../dev-utils/webdriver')

describe('Angular router integration', function () {
/**
Expand All @@ -49,6 +49,13 @@ describe('Angular router integration', function () {
'Home page'
)

let sendEvents = (await getLastServerCall(0, 1)).sendEvents
const [pageLoadTransaction] = sendEvents.transactions

expect(pageLoadTransaction.type).toBe('page-load')
expect(pageLoadTransaction.name).toBe('/home')
expect(pageLoadTransaction.spans.length).toBeGreaterThan(1)

await browser.waitUntil(
async () => {
/**
Expand Down Expand Up @@ -84,16 +91,9 @@ describe('Angular router integration', function () {
5000
)

const { sendEvents } = await waitForApmServerCalls(0, 2)
const { transactions } = sendEvents
expect(transactions.length).toBe(2)

const pageLoadTransaction = transactions[0]
expect(pageLoadTransaction.type).toBe('page-load')
expect(pageLoadTransaction.name).toBe('/home')
expect(pageLoadTransaction.spans.length).toBeGreaterThan(1)
sendEvents = (await getLastServerCall(0, 1)).sendEvents
const [routeTransaction] = sendEvents.transactions

const routeTransaction = transactions[1]
expect(routeTransaction.name).toBe('/contacts')
expect(routeTransaction.type).toBe('route-change')
expect(routeTransaction.spans.length).toBeGreaterThan(0)
Expand Down
6 changes: 6 additions & 0 deletions packages/rum-core/src/common/constants.js
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,11 @@ const REUSABILITY_THRESHOLD = 5000
*/
const MAX_SPAN_DURATION = 5 * 60 * 1000

/**
* The amount of time that should pass by before sending page load metrics
*/
const PAGE_LOAD_DELAY = 1000

/**
* Transaction & Span - Name & Types
*/
Expand Down Expand Up @@ -180,6 +185,7 @@ export {
RESOURCE_INITIATOR_TYPES,
REUSABILITY_THRESHOLD,
MAX_SPAN_DURATION,
PAGE_LOAD_DELAY,
PAGE_LOAD,
ROUTE_CHANGE,
NAME_UNKNOWN,
Expand Down
14 changes: 12 additions & 2 deletions packages/rum-core/src/common/utils.js
Original file line number Diff line number Diff line change
Expand Up @@ -328,12 +328,13 @@ function removeInvalidChars(key) {
return key.replace(/[.*"]/g, '_')
}

function getLatestNonXHRSpan(spans) {
function getLatestSpan(spans, typeFilter) {
let latestSpan = null
for (let i = 0; i < spans.length; i++) {
const span = spans[i]
if (
String(span.type).indexOf('external') === -1 &&
typeFilter &&
typeFilter(span.type) &&
(!latestSpan || latestSpan._end < span._end)
) {
latestSpan = span
Expand All @@ -342,6 +343,14 @@ function getLatestNonXHRSpan(spans) {
return latestSpan
}

function getLatestNonXHRSpan(spans) {
return getLatestSpan(spans, type => String(type).indexOf('external') === -1)
}

function getLatestXHRSpan(spans) {
return getLatestSpan(spans, type => String(type).indexOf('external') !== -1)
}

function getEarliestSpan(spans) {
let earliestSpan = spans[0]
for (let i = 1; i < spans.length; i++) {
Expand Down Expand Up @@ -414,6 +423,7 @@ export {
generateRandomId,
getEarliestSpan,
getLatestNonXHRSpan,
getLatestXHRSpan,
getDuration,
getTime,
now,
Expand Down
2 changes: 2 additions & 0 deletions packages/rum-core/src/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,7 @@ import {
import { patchAll, patchEventHandler } from './common/patching'
import { observePageVisibility } from './common/page-visibility'
import {
PAGE_LOAD_DELAY,
PAGE_LOAD,
ERROR,
CONFIG_SERVICE,
Expand Down Expand Up @@ -69,6 +70,7 @@ export {
scheduleMacroTask,
afterFrame,
ERROR,
PAGE_LOAD_DELAY,
PAGE_LOAD,
CONFIG_SERVICE,
LOGGING_SERVICE,
Expand Down
47 changes: 34 additions & 13 deletions packages/rum-core/src/performance-monitoring/transaction-service.js
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@ import {
extend,
getEarliestSpan,
getLatestNonXHRSpan,
getLatestXHRSpan,
isPerfTypeSupported,
generateRandomId
} from '../common/utils'
Expand All @@ -52,7 +53,8 @@ import {
TRUNCATED_TYPE,
FIRST_INPUT,
LAYOUT_SHIFT,
SESSION_TIMEOUT
SESSION_TIMEOUT,
PAGE_LOAD_DELAY
} from '../common/constants'
import { addTransactionContext } from '../common/context'
import { __DEV__, state } from '../state'
Expand Down Expand Up @@ -404,20 +406,39 @@ class TransactionService {
transaction._start = earliestSpan._start
}

/**
* Adjust end time of the transaction to match the latest
* span end time
*/
const latestSpan = getLatestNonXHRSpan(spans)
if (latestSpan && latestSpan._end > transaction._end) {
transaction._end = latestSpan._end
const latestSpan = getLatestNonXHRSpan(spans) || {}
const latestSpanEnd = latestSpan._end || 0

// Before ending the page-load transaction we are adding a delay to monitor events such as LCP and network requests.
// We need to make sure that we are not adding that extra time to the transaction end time
// if nothing has been monitored or if the last monitored event end time is less than the delay.
if (transaction.type === PAGE_LOAD) {
const transactionEndWithoutDelay = transaction._end - PAGE_LOAD_DELAY
const lcp = metrics.lcp || 0
const latestXHRSpan = getLatestXHRSpan(spans) || {}
const latestXHRSpanEnd = latestXHRSpan._end || 0

transaction._end = Math.max(
latestSpanEnd,
latestXHRSpanEnd,
lcp,
transactionEndWithoutDelay
)
} else if (latestSpanEnd > transaction._end) {
/**
* Adjust end time of the transaction to match the span end value
*/
transaction._end = latestSpanEnd
}

/**
* Set all spans that are longer than the transaction to
* be truncated spans
*/
const transactionEnd = transaction._end
this.truncateSpans(spans, transaction._end)
}

/**
* Set all spans that are longer than the transaction to
* be truncated spans
*/
truncateSpans(spans, transactionEnd) {
for (let i = 0; i < spans.length; i++) {
const span = spans[i]
if (span._end > transactionEnd) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,7 @@ import {
import { state } from '../../src/state'
import { isPerfTypeSupported } from '../../src/common/utils'
import Transaction from '../../src/performance-monitoring/transaction'
import { metrics } from '../../src/performance-monitoring/metrics'

describe('TransactionService', function () {
var transactionService
Expand Down Expand Up @@ -454,16 +455,19 @@ describe('TransactionService', function () {
it('should not produce negative durations while adjusting to the spans', () => {
const transaction = transactionService.startTransaction(
'transaction',
'transaction'
'transaction',
{
startTime: 10
}
)
let span = transaction.startSpan('test', 'test')
span.end()
span._end += 100
span = transaction.startSpan('test', 'external.http')
span.end(100)
span = transaction.startSpan('test', 'external.http', {
startTime: 10000000
})

span.end(11000000)

span.end()
span._start = 10000000
span._end = 11000000
transaction.end()
transactionService.adjustTransactionTime(transaction)
expect(span.duration()).toBe(0)
Expand All @@ -489,24 +493,129 @@ describe('TransactionService', function () {
})

it('should adjust transaction end based on latest span end', done => {
const transaction = transactionService.startTransaction('/', 'transaction')
const transactionStart = transaction._start
const transaction = transactionService.startTransaction(
'/',
'transaction',
{ startTime: 10 }
)

const firstSpan = transaction.startSpan('first-span-name', 'first-span')
firstSpan.end()
const longSpan = transaction.startSpan('long-span-name', 'long-span')
const lastSpan = transaction.startSpan('last-span-name', 'last-span')
lastSpan.end()
longSpan.end()
longSpan.end += 500
const longSpan = transaction.startSpan('long-span-name', 'long-span', {
startTime: 15
})
const lastSpan = transaction.startSpan('last-span-name', 'last-span', {
startTime: 20
})
lastSpan.end(45)
longSpan.end(60)

transaction.onEnd = () => {
transactionService.adjustTransactionTime(transaction)
expect(transaction._start).toBe(transactionStart)
expect(transaction._end).toBeGreaterThanOrEqual(longSpan._end)
expect(transaction._start).toBe(10)
expect(transaction._end).toBe(60)
done()
}
transaction.detectFinish()

transaction.end(50)
})

describe('page load transactions', () => {
beforeEach(() => {
metrics.lcp = undefined
})

it('should have its end time adjusted to match with LCP if it is the event that have lasted the most', done => {
const transaction = transactionService.startTransaction('/', PAGE_LOAD, {
startTime: 10
})

const span = transaction.startSpan('span-name', 'span')
span.end(15)

const externalSpan = transaction.startSpan('span-name', 'external')
externalSpan.end(20)

metrics.lcp = 25

transaction.onEnd = () => {
transactionService.adjustTransactionTime(transaction)
expect(transaction._start).toBe(10)
expect(transaction._end).toBe(metrics.lcp)
done()
}

transaction.end(1000)
})

it('should have its end time adjusted to match with network request span it is the event that have lasted the most', done => {
const transaction = transactionService.startTransaction('/', PAGE_LOAD, {
startTime: 10
})

const span = transaction.startSpan('span-name', 'span')
span.end(15)

const externalSpan = transaction.startSpan('span-name', 'external')
externalSpan.end(30)

metrics.lcp = 20

transaction.onEnd = () => {
transactionService.adjustTransactionTime(transaction)
expect(transaction._start).toBe(10)
expect(transaction._end).toBe(30)
done()
}

transaction.end(1000)
})

it('should have its end time adjusted to match with non-network request span it is the event that have lasted the most', done => {
const transaction = transactionService.startTransaction('/', PAGE_LOAD, {
startTime: 10
})

const span = transaction.startSpan('span-name', 'span')
span.end(50)

const externalSpan = transaction.startSpan('span-name', 'external')
externalSpan.end(30)

metrics.lcp = 20

transaction.onEnd = () => {
transactionService.adjustTransactionTime(transaction)
expect(transaction._start).toBe(10)
expect(transaction._end).toBe(50)
done()
}

transaction.end(1000)
})

it('should subtract the page load delay from its end time if no event has occurred after page load', done => {
const transaction = transactionService.startTransaction('/', PAGE_LOAD, {
startTime: 10
})

const span = transaction.startSpan('span-name', 'span')
span.end(15)

const externalSpan = transaction.startSpan('span-name', 'external')
externalSpan.end(20)

transaction.onEnd = () => {
const endBeforeAdjusting = transaction._end
transactionService.adjustTransactionTime(transaction)
expect(transaction._start).toBe(10)
expect(transaction._end).toBe(endBeforeAdjusting - 1000)
done()
}

// This represents the time when the page load has been triggered
const pageLoadTime = 30

transaction.end(pageLoadTime + 1000)
})
})

it('should truncate active spans after transaction ends', () => {
Expand Down
Loading

0 comments on commit 9ff2dd0

Please sign in to comment.