diff --git a/packages/rum/src/rum.ts b/packages/rum/src/rum.ts index 0e7de977ab..0a308b6f22 100644 --- a/packages/rum/src/rum.ts +++ b/packages/rum/src/rum.ts @@ -32,7 +32,7 @@ import { import { InternalContext, RumGlobal } from './rum.entry' import { RumSession } from './rumSession' import { getUserActionReference, UserActionMeasures, UserActionReference, UserActionType } from './userActionCollection' -import { viewContext, ViewMeasures } from './viewCollection' +import { viewContext, ViewLoadingType, ViewMeasures } from './viewCollection' export interface PerformancePaintTiming extends PerformanceEntry { entryType: 'paint' @@ -108,6 +108,8 @@ export interface RumViewEvent { documentVersion: number } view: { + loadingTime?: number + loadingType: ViewLoadingType measures: ViewMeasures } } @@ -261,6 +263,8 @@ function trackView(lifeCycle: LifeCycle, upsertRumEvent: (event: RumViewEvent, k documentVersion: view.documentVersion, }, view: { + loadingTime: view.loadingTime, + loadingType: view.loadingType, measures: view.measures, }, }, diff --git a/packages/rum/src/trackPageActivities.ts b/packages/rum/src/trackPageActivities.ts new file mode 100644 index 0000000000..913e9393d1 --- /dev/null +++ b/packages/rum/src/trackPageActivities.ts @@ -0,0 +1,148 @@ +import { monitor, Observable } from '@datadog/browser-core' +import { LifeCycle, LifeCycleEventType, Subscription } from './lifeCycle' + +// Delay to wait for a page activity to validate the tracking process +export const PAGE_ACTIVITY_VALIDATION_DELAY = 100 +// Delay to wait after a page activity to end the tracking process +export const PAGE_ACTIVITY_END_DELAY = 100 +// Maximum duration of the tracking process +export const PAGE_ACTIVITY_MAX_DURATION = 10_000 + +export interface PageActivityEvent { + isBusy: boolean +} + +export function waitIdlePageActivity( + lifeCycle: LifeCycle, + completionCallback: (hadActivity: boolean, endTime: number) => void +): { stop(): void } { + const { observable: pageActivitiesObservable, stop: stopPageActivitiesTracking } = trackPageActivities(lifeCycle) + + const { stop: stopWaitPageActivitiesCompletion } = waitPageActivitiesCompletion( + pageActivitiesObservable, + stopPageActivitiesTracking, + completionCallback + ) + + function stop() { + stopWaitPageActivitiesCompletion() + stopPageActivitiesTracking() + } + + return { stop } +} + +// Automatic user action collection lifecycle overview: +// (Start new trackPageActivities) +// .-------------------'--------------------. +// v v +// [Wait for a page activity ] [Wait for a maximum duration] +// [timeout: VALIDATION_DELAY] [ timeout: MAX_DURATION ] +// / \ | +// v v | +// [No page activity] [Page activity] | +// | |,----------------------. | +// v v | | +// (Discard) [Wait for a page activity] | | +// [ timeout: END_DELAY ] | | +// / \ | | +// v v | | +// [No page activity] [Page activity] | | +// | | | | +// | '------------' | +// '-----------. ,--------------------' +// v +// (End) +// +// Note: because MAX_DURATION > VALIDATION_DELAY, we are sure that if the process is still alive +// after MAX_DURATION, it has been validated. +export function trackPageActivities(lifeCycle: LifeCycle): { observable: Observable; stop(): void } { + const observable = new Observable() + const subscriptions: Subscription[] = [] + let firstRequestId: undefined | number + let pendingRequestsCount = 0 + + subscriptions.push(lifeCycle.subscribe(LifeCycleEventType.DOM_MUTATED, () => notifyPageActivity())) + + subscriptions.push( + lifeCycle.subscribe(LifeCycleEventType.PERFORMANCE_ENTRY_COLLECTED, (entry) => { + if (entry.entryType !== 'resource') { + return + } + + notifyPageActivity() + }) + ) + + subscriptions.push( + lifeCycle.subscribe(LifeCycleEventType.REQUEST_STARTED, (startEvent) => { + if (firstRequestId === undefined) { + firstRequestId = startEvent.requestId + } + + pendingRequestsCount += 1 + notifyPageActivity() + }) + ) + + subscriptions.push( + lifeCycle.subscribe(LifeCycleEventType.REQUEST_COMPLETED, (request) => { + // If the request started before the tracking start, ignore it + if (firstRequestId === undefined || request.requestId < firstRequestId) { + return + } + pendingRequestsCount -= 1 + notifyPageActivity() + }) + ) + + function notifyPageActivity() { + observable.notify({ isBusy: pendingRequestsCount > 0 }) + } + + return { + observable, + stop() { + subscriptions.forEach((s) => s.unsubscribe()) + }, + } +} + +export function waitPageActivitiesCompletion( + pageActivitiesObservable: Observable, + stopPageActivitiesTracking: () => void, + completionCallback: (hadActivity: boolean, endTime: number) => void +): { stop(): void } { + let idleTimeoutId: ReturnType + let hasCompleted = false + + const validationTimeoutId = setTimeout(monitor(() => complete(false, 0)), PAGE_ACTIVITY_VALIDATION_DELAY) + const maxDurationTimeoutId = setTimeout(monitor(() => complete(true, performance.now())), PAGE_ACTIVITY_MAX_DURATION) + + pageActivitiesObservable.subscribe(({ isBusy }) => { + clearTimeout(validationTimeoutId) + clearTimeout(idleTimeoutId) + const lastChangeTime = performance.now() + if (!isBusy) { + idleTimeoutId = setTimeout(monitor(() => complete(true, lastChangeTime)), PAGE_ACTIVITY_END_DELAY) + } + }) + + function stop() { + hasCompleted = true + clearTimeout(validationTimeoutId) + clearTimeout(idleTimeoutId) + clearTimeout(maxDurationTimeoutId) + stopPageActivitiesTracking() + } + + function complete(hadActivity: boolean, endTime: number) { + if (hasCompleted) { + return + } + stop() + completionCallback(hadActivity, endTime) + } + + return { stop } +} diff --git a/packages/rum/src/userActionCollection.ts b/packages/rum/src/userActionCollection.ts index 818d193352..c732097c2b 100644 --- a/packages/rum/src/userActionCollection.ts +++ b/packages/rum/src/userActionCollection.ts @@ -1,44 +1,11 @@ -import { Context, DOM_EVENT, generateUUID, monitor, Observable } from '@datadog/browser-core' +import { Context, DOM_EVENT, generateUUID, noop } from '@datadog/browser-core' import { getElementContent } from './getElementContent' -import { LifeCycle, LifeCycleEventType, Subscription } from './lifeCycle' +import { LifeCycle, LifeCycleEventType } from './lifeCycle' import { trackEventCounts } from './trackEventCounts' - -// Automatic user action collection lifecycle overview: -// -// (Start) -// .--------------'----------------------. -// v v -// [Wait for a page activity ] [Wait for a maximum duration] -// [timeout: VALIDATION_DELAY] [ timeout: MAX_DURATION ] -// / \ | -// v v | -// [No page activity] [Page activity] | -// | |,----------------------. | -// v v | | -// (Discard) [Wait for a page activity] | | -// [ timeout: END_DELAY ] | | -// / \ | | -// v v | | -// [No page activity] [Page activity] | | -// | | | | -// | '------------' | -// '-----------. ,--------------------' -// v -// (End) -// -// Note: because MAX_DURATION > VALIDATION_DELAY, we are sure that if the user action is still alive -// after MAX_DURATION, it has been validated. - -// Delay to wait for a page activity to validate the user action -export const USER_ACTION_VALIDATION_DELAY = 100 -// Delay to wait after a page activity to end the user action -export const USER_ACTION_END_DELAY = 100 -// Maximum duration of a user action -export const USER_ACTION_MAX_DURATION = 10_000 +import { waitIdlePageActivity } from './trackPageActivities' export enum UserActionType { CLICK = 'click', - LOAD_VIEW = 'load_view', CUSTOM = 'custom', } @@ -55,7 +22,7 @@ interface CustomUserAction { } export interface AutoUserAction { - type: UserActionType.LOAD_VIEW | UserActionType.CLICK + type: UserActionType.CLICK id: string name: string startTime: number @@ -65,43 +32,52 @@ export interface AutoUserAction { export type UserAction = CustomUserAction | AutoUserAction +interface PendingAutoUserAction { + id: string + startTime: number + stop(): void +} +let pendingAutoUserAction: PendingAutoUserAction | undefined + export function startUserActionCollection(lifeCycle: LifeCycle) { + addEventListener(DOM_EVENT.CLICK, processClick, { capture: true }) function processClick(event: Event) { if (!(event.target instanceof Element)) { return } - newUserAction(lifeCycle, UserActionType.CLICK, getElementContent(event.target)) } - addEventListener(DOM_EVENT.CLICK, processClick, { capture: true }) + // New views trigger the cancellation of the current pending User Action + lifeCycle.subscribe(LifeCycleEventType.VIEW_COLLECTED, () => { + if (pendingAutoUserAction) { + pendingAutoUserAction.stop() + } + }) return { stop() { + if (pendingAutoUserAction) { + pendingAutoUserAction.stop() + } removeEventListener(DOM_EVENT.CLICK, processClick, { capture: true }) }, } } -let currentUserAction: { id: string; startTime: number } | undefined - function newUserAction(lifeCycle: LifeCycle, type: UserActionType, name: string) { - if (currentUserAction) { - // Discard any new user action if another one is already occuring. + if (pendingAutoUserAction) { + // Discard any new user action if another one is already occurring. return } const id = generateUUID() const startTime = performance.now() - currentUserAction = { id, startTime } - const { observable: pageActivitiesObservable, stop: stopPageActivitiesTracking } = trackPageActivities(lifeCycle) const { eventCounts, stop: stopEventCountsTracking } = trackEventCounts(lifeCycle) - waitUserActionCompletion(pageActivitiesObservable, (endTime) => { - stopPageActivitiesTracking() - stopEventCountsTracking() - if (endTime !== undefined) { + const { stop: stopWaitIdlePageActivity } = waitIdlePageActivity(lifeCycle, (hadActivity, endTime) => { + if (hadActivity) { lifeCycle.notify(LifeCycleEventType.USER_ACTION_COLLECTED, { id, name, @@ -115,113 +91,36 @@ function newUserAction(lifeCycle: LifeCycle, type: UserActionType, name: string) }, }) } + + stopEventCountsTracking() + pendingAutoUserAction = undefined }) + + pendingAutoUserAction = { + id, + startTime, + stop() { + stopEventCountsTracking() + stopWaitIdlePageActivity() + pendingAutoUserAction = undefined + }, + } } export interface UserActionReference { id: string } export function getUserActionReference(time?: number): UserActionReference | undefined { - if (!currentUserAction || (time !== undefined && time < currentUserAction.startTime)) { + if (!pendingAutoUserAction || (time !== undefined && time < pendingAutoUserAction.startTime)) { return undefined } - return { id: currentUserAction.id } -} - -export interface PageActivityEvent { - isBusy: boolean -} - -function trackPageActivities(lifeCycle: LifeCycle): { observable: Observable; stop(): void } { - const observable = new Observable() - const subscriptions: Subscription[] = [] - let firstRequestId: undefined | number - let pendingRequestsCount = 0 - - subscriptions.push(lifeCycle.subscribe(LifeCycleEventType.DOM_MUTATED, () => notifyPageActivity())) - - subscriptions.push( - lifeCycle.subscribe(LifeCycleEventType.PERFORMANCE_ENTRY_COLLECTED, (entry) => { - if (entry.entryType !== 'resource') { - return - } - - notifyPageActivity() - }) - ) - - subscriptions.push( - lifeCycle.subscribe(LifeCycleEventType.REQUEST_STARTED, (startEvent) => { - if (firstRequestId === undefined) { - firstRequestId = startEvent.requestId - } - - pendingRequestsCount += 1 - notifyPageActivity() - }) - ) - - subscriptions.push( - lifeCycle.subscribe(LifeCycleEventType.REQUEST_COMPLETED, (request) => { - // If the request started before the tracking start, ignore it - if (firstRequestId === undefined || request.requestId < firstRequestId) { - return - } - pendingRequestsCount -= 1 - notifyPageActivity() - }) - ) - - function notifyPageActivity() { - observable.notify({ isBusy: pendingRequestsCount > 0 }) - } - - return { - observable, - stop() { - subscriptions.forEach((s) => s.unsubscribe()) - }, - } -} - -function waitUserActionCompletion( - pageActivitiesObservable: Observable, - completionCallback: (endTime: number | undefined) => void -) { - let idleTimeoutId: ReturnType - let hasCompleted = false - - const validationTimeoutId = setTimeout(monitor(() => complete(undefined)), USER_ACTION_VALIDATION_DELAY) - const maxDurationTimeoutId = setTimeout(monitor(() => complete(performance.now())), USER_ACTION_MAX_DURATION) - - pageActivitiesObservable.subscribe(({ isBusy }) => { - clearTimeout(validationTimeoutId) - clearTimeout(idleTimeoutId) - const lastChangeTime = performance.now() - if (!isBusy) { - idleTimeoutId = setTimeout(monitor(() => complete(lastChangeTime)), USER_ACTION_END_DELAY) - } - }) - - function complete(endTime: number | undefined) { - if (hasCompleted) { - return - } - hasCompleted = true - clearTimeout(validationTimeoutId) - clearTimeout(idleTimeoutId) - clearTimeout(maxDurationTimeoutId) - currentUserAction = undefined - completionCallback(endTime) - } + return { id: pendingAutoUserAction.id } } export const $$tests = { newUserAction, - trackPageActivities, resetUserAction() { - currentUserAction = undefined + pendingAutoUserAction = undefined }, - waitUserActionCompletion, } diff --git a/packages/rum/src/viewCollection.ts b/packages/rum/src/viewCollection.ts index 2d829eccfd..15a53206b1 100644 --- a/packages/rum/src/viewCollection.ts +++ b/packages/rum/src/viewCollection.ts @@ -4,6 +4,7 @@ import { LifeCycle, LifeCycleEventType } from './lifeCycle' import { PerformancePaintTiming } from './rum' import { RumSession } from './rumSession' import { trackEventCounts } from './trackEventCounts' +import { waitIdlePageActivity } from './trackPageActivities' export interface View { id: string @@ -12,6 +13,8 @@ export interface View { documentVersion: number startTime: number duration: number + loadingTime?: number | undefined + loadingType: ViewLoadingType } export interface ViewMeasures { @@ -26,26 +29,31 @@ export interface ViewMeasures { userActionCount: number } +export enum ViewLoadingType { + INITIAL_LOAD = 'initial_load', + ROUTE_CHANGE = 'route_change', +} + export const THROTTLE_VIEW_UPDATE_PERIOD = 3000 export function startViewCollection(location: Location, lifeCycle: LifeCycle, session: RumSession) { let currentLocation = { ...location } const startOrigin = 0 - let currentView = newView(lifeCycle, currentLocation, session, startOrigin) + let currentView = newView(lifeCycle, currentLocation, session, ViewLoadingType.INITIAL_LOAD, startOrigin) // Renew view on history changes trackHistory(() => { if (areDifferentViews(currentLocation, location)) { currentLocation = { ...location } currentView.end() - currentView = newView(lifeCycle, currentLocation, session) + currentView = newView(lifeCycle, currentLocation, session, ViewLoadingType.ROUTE_CHANGE) } }) // Renew view on session renewal lifeCycle.subscribe(LifeCycleEventType.SESSION_RENEWED, () => { currentView.end() - currentView = newView(lifeCycle, currentLocation, session) + currentView = newView(lifeCycle, currentLocation, session, ViewLoadingType.ROUTE_CHANGE) }) // End the current view on page unload @@ -66,6 +74,7 @@ function newView( lifeCycle: LifeCycle, location: Location, session: RumSession, + loadingType: ViewLoadingType, startOrigin: number = performance.now() ) { // Setup initial values @@ -77,6 +86,7 @@ function newView( userActionCount: 0, } let documentVersion = 0 + let loadingTime: number | undefined viewContext = { id, location, sessionId: session.getId() } @@ -95,6 +105,12 @@ function newView( const { stop: stopTimingsTracking } = trackTimings(lifeCycle, updateMeasures) const { stop: stopEventCountsTracking } = trackEventCounts(lifeCycle, updateMeasures) + function updateLoadingTime(loadingTimeValue: number | undefined) { + loadingTime = loadingTimeValue + scheduleViewUpdate() + } + const { stop: stopLoadingTimeTracking } = trackLoadingTime(lifeCycle, updateLoadingTime) + // Initial view update updateView() @@ -103,6 +119,8 @@ function newView( lifeCycle.notify(LifeCycleEventType.VIEW_COLLECTED, { documentVersion, id, + loadingTime, + loadingType, location, measures, duration: performance.now() - startOrigin, @@ -114,6 +132,7 @@ function newView( end() { stopTimingsTracking() stopEventCountsTracking() + stopLoadingTimeTracking() // prevent pending view updates execution stopScheduleViewUpdate() // Make a final view update @@ -175,3 +194,16 @@ function trackTimings(lifeCycle: LifeCycle, callback: (timings: Timings) => void ) return { stop: stopPerformanceTracking } } + +function trackLoadingTime(lifeCycle: LifeCycle, callback: (loadingTimeValue: number | undefined) => void) { + const startTime: number = performance.now() + const { stop: stopWaitIdlePageActivity } = waitIdlePageActivity(lifeCycle, (hadActivity, endTime) => { + if (hadActivity) { + callback(endTime - startTime) + } else { + callback(undefined) + } + }) + + return { stop: stopWaitIdlePageActivity } +} diff --git a/packages/rum/test/trackPageActivities.spec.ts b/packages/rum/test/trackPageActivities.spec.ts new file mode 100644 index 0000000000..22c2a98131 --- /dev/null +++ b/packages/rum/test/trackPageActivities.spec.ts @@ -0,0 +1,255 @@ +import { noop, Observable, RequestCompleteEvent } from '@datadog/browser-core' +import { LifeCycle, LifeCycleEventType } from '../src/lifeCycle' +import { + PAGE_ACTIVITY_END_DELAY, + PAGE_ACTIVITY_MAX_DURATION, + PAGE_ACTIVITY_VALIDATION_DELAY, + PageActivityEvent, + trackPageActivities, + waitPageActivitiesCompletion, +} from '../src/trackPageActivities' + +// Used to wait some time after the creation of a user action +const BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY = PAGE_ACTIVITY_VALIDATION_DELAY * 0.8 +// Used to wait some time before the (potential) end of a user action +const BEFORE_PAGE_ACTIVITY_END_DELAY = PAGE_ACTIVITY_END_DELAY * 0.8 +// A long delay used to wait after any user action is finished. +const EXPIRE_DELAY = PAGE_ACTIVITY_MAX_DURATION * 10 + +function mockClock() { + beforeEach(() => { + jasmine.clock().install() + jasmine.clock().mockDate() + spyOn(performance, 'now').and.callFake(() => Date.now()) + }) + + afterEach(() => { + jasmine.clock().uninstall() + }) + + return { + tick(ms: number) { + jasmine.clock().tick(ms) + }, + expire() { + // Make sure no user action is still pending + jasmine.clock().tick(EXPIRE_DELAY) + }, + } +} + +function eventsCollector() { + const events: T[] = [] + beforeEach(() => { + events.length = 0 + }) + return { + events, + pushEvent(event: T) { + events.push(event) + }, + } +} + +describe('trackPagePageActivities', () => { + const { events, pushEvent } = eventsCollector() + it('emits an activity event on dom mutation', () => { + const lifeCycle = new LifeCycle() + trackPageActivities(lifeCycle).observable.subscribe(pushEvent) + lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) + expect(events).toEqual([{ isBusy: false }]) + }) + + it('emits an activity event on resource collected', () => { + const lifeCycle = new LifeCycle() + trackPageActivities(lifeCycle).observable.subscribe(pushEvent) + const performanceEntry = { + entryType: 'resource', + } + lifeCycle.notify(LifeCycleEventType.PERFORMANCE_ENTRY_COLLECTED, performanceEntry as PerformanceEntry) + expect(events).toEqual([{ isBusy: false }]) + }) + + it('does not emit an activity event when a navigation occurs', () => { + const lifeCycle = new LifeCycle() + trackPageActivities(lifeCycle).observable.subscribe(pushEvent) + const performanceEntry = { + entryType: 'navigation', + } + lifeCycle.notify(LifeCycleEventType.PERFORMANCE_ENTRY_COLLECTED, performanceEntry as PerformanceEntry) + expect(events).toEqual([]) + }) + + it('stops emiting activities after calling stop()', () => { + const lifeCycle = new LifeCycle() + const { stop, observable } = trackPageActivities(lifeCycle) + observable.subscribe(pushEvent) + + lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) + expect(events).toEqual([{ isBusy: false }]) + + stop() + + lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) + lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) + + expect(events).toEqual([{ isBusy: false }]) + }) + + describe('requests', () => { + function makeFakeRequestCompleteEvent(requestId: number): RequestCompleteEvent { + return { requestId } as any + } + it('emits an activity event when a request starts', () => { + const lifeCycle = new LifeCycle() + trackPageActivities(lifeCycle).observable.subscribe(pushEvent) + lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { + requestId: 10, + }) + expect(events).toEqual([{ isBusy: true }]) + }) + + it('emits an activity event when a request completes', () => { + const lifeCycle = new LifeCycle() + trackPageActivities(lifeCycle).observable.subscribe(pushEvent) + lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { + requestId: 10, + }) + lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(10)) + expect(events).toEqual([{ isBusy: true }, { isBusy: false }]) + }) + + it('ignores requests that has started before', () => { + const lifeCycle = new LifeCycle() + trackPageActivities(lifeCycle).observable.subscribe(pushEvent) + lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(10)) + expect(events).toEqual([]) + }) + + it('keeps emiting busy events while all requests are not completed', () => { + const lifeCycle = new LifeCycle() + trackPageActivities(lifeCycle).observable.subscribe(pushEvent) + lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { + requestId: 10, + }) + lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { + requestId: 11, + }) + lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(9)) + lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(11)) + lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(10)) + expect(events).toEqual([{ isBusy: true }, { isBusy: true }, { isBusy: true }, { isBusy: false }]) + }) + }) +}) + +describe('waitPageActivitiesCompletion', () => { + const clock = mockClock() + + it('should not collect an event that is not followed by page activity', (done) => { + waitPageActivitiesCompletion(new Observable(), noop, (hadActivity, endTime) => { + expect(hadActivity).toBeFalse() + expect(endTime).toBeFalsy() + done() + }) + + clock.expire() + }) + + it('should collect an event that is followed by page activity', (done) => { + const activityObservable = new Observable() + + const startTime = performance.now() + waitPageActivitiesCompletion(activityObservable, noop, (hadActivity, endTime) => { + expect(hadActivity).toBeTrue() + expect(endTime).toEqual(startTime + BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) + done() + }) + + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) + activityObservable.notify({ isBusy: false }) + + clock.expire() + }) + + describe('extend with activities', () => { + it('is extended while there is page activities', (done) => { + const activityObservable = new Observable() + const startTime = performance.now() + + // Extend the user action but stops before PAGE_ACTIVITY_MAX_DURATION + const extendCount = Math.floor(PAGE_ACTIVITY_MAX_DURATION / BEFORE_PAGE_ACTIVITY_END_DELAY - 1) + + waitPageActivitiesCompletion(activityObservable, noop, (hadActivity, endTime) => { + expect(hadActivity).toBeTrue() + expect(endTime).toBe(startTime + (extendCount + 1) * BEFORE_PAGE_ACTIVITY_END_DELAY) + done() + }) + + for (let i = 0; i < extendCount; i += 1) { + clock.tick(BEFORE_PAGE_ACTIVITY_END_DELAY) + activityObservable.notify({ isBusy: false }) + } + + clock.expire() + }) + + it('expires after a limit', (done) => { + const activityObservable = new Observable() + let stop = false + const startTime = performance.now() + + // Extend the user action until it's more than PAGE_ACTIVITY_MAX_DURATION + const extendCount = Math.ceil(PAGE_ACTIVITY_MAX_DURATION / BEFORE_PAGE_ACTIVITY_END_DELAY + 1) + + waitPageActivitiesCompletion(activityObservable, noop, (hadActivity, endTime) => { + expect(hadActivity).toBeTrue() + expect(endTime).toBe(startTime + PAGE_ACTIVITY_MAX_DURATION) + stop = true + done() + }) + + for (let i = 0; i < extendCount && !stop; i += 1) { + clock.tick(BEFORE_PAGE_ACTIVITY_END_DELAY) + activityObservable.notify({ isBusy: false }) + } + + clock.expire() + }) + }) + + describe('busy activities', () => { + it('is extended while the page is busy', (done) => { + const activityObservable = new Observable() + const startTime = performance.now() + waitPageActivitiesCompletion(activityObservable, noop, (hadActivity, endTime) => { + expect(hadActivity).toBeTrue() + expect(endTime).toBe(startTime + BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY + PAGE_ACTIVITY_END_DELAY * 2) + done() + }) + + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) + activityObservable.notify({ isBusy: true }) + + clock.tick(PAGE_ACTIVITY_END_DELAY * 2) + activityObservable.notify({ isBusy: false }) + + clock.expire() + }) + + it('expires is the page is busy for too long', (done) => { + const activityObservable = new Observable() + const startTime = performance.now() + waitPageActivitiesCompletion(activityObservable, noop, (hadActivity, endTime) => { + expect(hadActivity).toBeTrue() + expect(endTime).toBe(startTime + PAGE_ACTIVITY_MAX_DURATION) + done() + }) + + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) + activityObservable.notify({ isBusy: true }) + + clock.expire() + }) + }) +}) diff --git a/packages/rum/test/userActionCollection.spec.ts b/packages/rum/test/userActionCollection.spec.ts index e5605fbef2..01fbb32728 100644 --- a/packages/rum/test/userActionCollection.spec.ts +++ b/packages/rum/test/userActionCollection.spec.ts @@ -1,27 +1,24 @@ -import { DOM_EVENT, ErrorMessage, Observable, RequestCompleteEvent } from '@datadog/browser-core' +import { DOM_EVENT, ErrorMessage } from '@datadog/browser-core' import { LifeCycle, LifeCycleEventType } from '../src/lifeCycle' +import { PAGE_ACTIVITY_MAX_DURATION, PAGE_ACTIVITY_VALIDATION_DELAY } from '../src/trackPageActivities' import { $$tests, AutoUserAction, getUserActionReference, - PageActivityEvent, startUserActionCollection, - USER_ACTION_END_DELAY, - USER_ACTION_MAX_DURATION, - USER_ACTION_VALIDATION_DELAY, UserAction, UserActionType, } from '../src/userActionCollection' -const { waitUserActionCompletion, trackPageActivities, resetUserAction, newUserAction } = $$tests +import { View } from '../src/viewCollection' + +const { resetUserAction, newUserAction } = $$tests // Used to wait some time after the creation of a user action -const BEFORE_USER_ACTION_VALIDATION_DELAY = USER_ACTION_VALIDATION_DELAY * 0.8 -// Used to wait some time before the (potential) end of a user action -const BEFORE_USER_ACTION_END_DELAY = USER_ACTION_END_DELAY * 0.8 +const BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY = PAGE_ACTIVITY_VALIDATION_DELAY * 0.8 // Used to wait some time but it doesn't matter how much. const SOME_ARBITRARY_DELAY = 50 // A long delay used to wait after any user action is finished. -const EXPIRE_DELAY = USER_ACTION_MAX_DURATION * 10 +const EXPIRE_DELAY = PAGE_ACTIVITY_MAX_DURATION * 10 function mockClock() { beforeEach(() => { @@ -81,9 +78,9 @@ describe('startUserActionCollection', () => { userActionCollectionSubscription.stop() }) - it('starts a user action when clicking on an element', () => { + function mockValidatedClickUserAction() { button.addEventListener(DOM_EVENT.CLICK, () => { - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY) + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) // Since we don't collect dom mutations for this test, manually dispatch one lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) }) @@ -92,9 +89,29 @@ describe('startUserActionCollection', () => { button.click() clock.expire() + } + + it('cancels pending user action on view loading', () => { + button.addEventListener(DOM_EVENT.CLICK, () => { + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) + // Since we don't collect dom mutations for this test, manually dispatch one + lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) + }) + + clock.tick(SOME_ARBITRARY_DELAY) + button.click() + const fakeView = {} + lifeCycle.notify(LifeCycleEventType.VIEW_COLLECTED, fakeView as View) + clock.expire() + + expect(events).toEqual([]) + }) + + it('starts a user action when clicking on an element', () => { + mockValidatedClickUserAction() expect(events).toEqual([ { - duration: BEFORE_USER_ACTION_VALIDATION_DELAY, + duration: BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY, id: jasmine.any(String), measures: { errorCount: 0, @@ -136,7 +153,7 @@ describe('getUserActionReference', () => { expect(userActionReference).toBeDefined() - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY) + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) expect(getUserActionReference()).toBeDefined() @@ -155,9 +172,9 @@ describe('getUserActionReference', () => { clock.tick(SOME_ARBITRARY_DELAY) newUserAction(new LifeCycle(), UserActionType.CLICK, 'test') - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY * 0.5) + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY * 0.5) const timeAfterStartingUserAction = Date.now() - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY * 0.5) + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY * 0.5) expect(getUserActionReference()).toBeDefined() expect(getUserActionReference(timeAfterStartingUserAction)).toBeDefined() @@ -178,7 +195,7 @@ describe('newUserAction', () => { newUserAction(lifeCycle, UserActionType.CLICK, 'test-1') newUserAction(lifeCycle, UserActionType.CLICK, 'test-2') - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY) + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) clock.expire() @@ -194,7 +211,7 @@ describe('newUserAction', () => { newUserAction(lifeCycle, UserActionType.CLICK, 'test-1') lifeCycle.notify(LifeCycleEventType.ERROR_COLLECTED, error as ErrorMessage) - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY) + clock.tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) lifeCycle.notify(LifeCycleEventType.ERROR_COLLECTED, error as ErrorMessage) @@ -210,200 +227,3 @@ describe('newUserAction', () => { }) }) }) - -describe('trackPagePageActivities', () => { - const { events, pushEvent } = eventsCollector() - it('emits an activity event on dom mutation', () => { - const lifeCycle = new LifeCycle() - trackPageActivities(lifeCycle).observable.subscribe(pushEvent) - lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) - expect(events).toEqual([{ isBusy: false }]) - }) - - it('emits an activity event on resource collected', () => { - const lifeCycle = new LifeCycle() - trackPageActivities(lifeCycle).observable.subscribe(pushEvent) - const performanceEntry = { - entryType: 'resource', - } - lifeCycle.notify(LifeCycleEventType.PERFORMANCE_ENTRY_COLLECTED, performanceEntry as PerformanceEntry) - expect(events).toEqual([{ isBusy: false }]) - }) - - it('does not emit an activity event when a navigation occurs', () => { - const lifeCycle = new LifeCycle() - trackPageActivities(lifeCycle).observable.subscribe(pushEvent) - const performanceEntry = { - entryType: 'navigation', - } - lifeCycle.notify(LifeCycleEventType.PERFORMANCE_ENTRY_COLLECTED, performanceEntry as PerformanceEntry) - expect(events).toEqual([]) - }) - - it('stops emiting activities after calling stop()', () => { - const lifeCycle = new LifeCycle() - const { stop, observable } = trackPageActivities(lifeCycle) - observable.subscribe(pushEvent) - - lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) - expect(events).toEqual([{ isBusy: false }]) - - stop() - - lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) - lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) - - expect(events).toEqual([{ isBusy: false }]) - }) - - describe('requests', () => { - function makeFakeRequestCompleteEvent(requestId: number): RequestCompleteEvent { - return { requestId } as any - } - it('emits an activity event when a request starts', () => { - const lifeCycle = new LifeCycle() - trackPageActivities(lifeCycle).observable.subscribe(pushEvent) - lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { - requestId: 10, - }) - expect(events).toEqual([{ isBusy: true }]) - }) - - it('emits an activity event when a request completes', () => { - const lifeCycle = new LifeCycle() - trackPageActivities(lifeCycle).observable.subscribe(pushEvent) - lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { - requestId: 10, - }) - lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(10)) - expect(events).toEqual([{ isBusy: true }, { isBusy: false }]) - }) - - it('ignores requests that has started before', () => { - const lifeCycle = new LifeCycle() - trackPageActivities(lifeCycle).observable.subscribe(pushEvent) - lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(10)) - expect(events).toEqual([]) - }) - - it('keeps emiting busy events while all requests are not completed', () => { - const lifeCycle = new LifeCycle() - trackPageActivities(lifeCycle).observable.subscribe(pushEvent) - lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { - requestId: 10, - }) - lifeCycle.notify(LifeCycleEventType.REQUEST_STARTED, { - requestId: 11, - }) - lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(9)) - lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(11)) - lifeCycle.notify(LifeCycleEventType.REQUEST_COMPLETED, makeFakeRequestCompleteEvent(10)) - expect(events).toEqual([{ isBusy: true }, { isBusy: true }, { isBusy: true }, { isBusy: false }]) - }) - }) -}) - -describe('waitUserActionCompletion', () => { - const clock = mockClock() - - it('should not collect an event that is not followed by page activity', (done) => { - waitUserActionCompletion(new Observable(), (endTime) => { - expect(endTime).toBeUndefined() - done() - }) - - clock.expire() - }) - - it('should collect an event that is followed by page activity', (done) => { - const activityObservable = new Observable() - - const startTime = performance.now() - waitUserActionCompletion(activityObservable, (endTime) => { - expect(endTime).toEqual(startTime + BEFORE_USER_ACTION_VALIDATION_DELAY) - done() - }) - - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY) - activityObservable.notify({ isBusy: false }) - - clock.expire() - }) - - describe('extend with activities', () => { - it('is extended while there is page activities', (done) => { - const activityObservable = new Observable() - const startTime = performance.now() - - // Extend the user action but stops before USER_ACTION_MAX_DURATION - const extendCount = Math.floor(USER_ACTION_MAX_DURATION / BEFORE_USER_ACTION_END_DELAY - 1) - - waitUserActionCompletion(activityObservable, (endTime) => { - expect(endTime).toBe(startTime + (extendCount + 1) * BEFORE_USER_ACTION_END_DELAY) - done() - }) - - for (let i = 0; i < extendCount; i += 1) { - clock.tick(BEFORE_USER_ACTION_END_DELAY) - activityObservable.notify({ isBusy: false }) - } - - clock.expire() - }) - - it('expires after a limit', (done) => { - const activityObservable = new Observable() - let stop = false - const startTime = performance.now() - - // Extend the user action until it's more than USER_ACTION_MAX_DURATION - const extendCount = Math.ceil(USER_ACTION_MAX_DURATION / BEFORE_USER_ACTION_END_DELAY + 1) - - waitUserActionCompletion(activityObservable, (endTime) => { - expect(endTime).toBe(startTime + USER_ACTION_MAX_DURATION) - stop = true - done() - }) - - for (let i = 0; i < extendCount && !stop; i += 1) { - clock.tick(BEFORE_USER_ACTION_END_DELAY) - activityObservable.notify({ isBusy: false }) - } - - clock.expire() - }) - }) - - describe('busy activities', () => { - it('is extended while the page is busy', (done) => { - const activityObservable = new Observable() - const startTime = performance.now() - waitUserActionCompletion(activityObservable, (endTime) => { - expect(endTime).toBe(startTime + BEFORE_USER_ACTION_VALIDATION_DELAY + USER_ACTION_END_DELAY * 2) - done() - }) - - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY) - activityObservable.notify({ isBusy: true }) - - clock.tick(USER_ACTION_END_DELAY * 2) - activityObservable.notify({ isBusy: false }) - - clock.expire() - }) - - it('expires is the page is busy for too long', (done) => { - const activityObservable = new Observable() - const startTime = performance.now() - waitUserActionCompletion(activityObservable, (endTime) => { - expect(endTime).toBe(startTime + USER_ACTION_MAX_DURATION) - done() - }) - - clock.tick(BEFORE_USER_ACTION_VALIDATION_DELAY) - activityObservable.notify({ isBusy: true }) - - clock.expire() - }) - }) -}) diff --git a/packages/rum/test/viewCollection.spec.ts b/packages/rum/test/viewCollection.spec.ts index 096f9e8aed..16dd73735a 100644 --- a/packages/rum/test/viewCollection.spec.ts +++ b/packages/rum/test/viewCollection.spec.ts @@ -4,7 +4,23 @@ import { LifeCycle, LifeCycleEventType } from '../src/lifeCycle' import { PerformanceLongTaskTiming, PerformancePaintTiming } from '../src/rum' import { RumSession } from '../src/rumSession' import { UserAction, UserActionType } from '../src/userActionCollection' -import { startViewCollection, THROTTLE_VIEW_UPDATE_PERIOD, View, viewContext } from '../src/viewCollection' +import { + startViewCollection, + THROTTLE_VIEW_UPDATE_PERIOD, + View, + viewContext, + ViewLoadingType, +} from '../src/viewCollection' + +import { + PAGE_ACTIVITY_END_DELAY, + PAGE_ACTIVITY_MAX_DURATION, + PAGE_ACTIVITY_VALIDATION_DELAY, +} from '../src/trackPageActivities' + +const AFTER_PAGE_ACTIVITY_MAX_DURATION = PAGE_ACTIVITY_MAX_DURATION * 1.1 +const BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY = PAGE_ACTIVITY_VALIDATION_DELAY * 0.8 +const AFTER_PAGE_ACTIVITY_END_DELAY = PAGE_ACTIVITY_END_DELAY * 1.1 function setup(lifeCycle: LifeCycle = new LifeCycle()) { spyOn(history, 'pushState').and.callFake((_: any, __: string, pathname: string) => { @@ -99,6 +115,65 @@ describe('rum track renew session', () => { }) }) +describe('rum track load duration', () => { + let lifeCycle: LifeCycle + let getViewEvent: (index: number) => View + + beforeEach(() => { + jasmine.clock().install() + ;({ lifeCycle, getViewEvent } = spyOnViews()) + }) + + afterEach(() => { + jasmine.clock().uninstall() + }) + + it('should collect intital view type as "initial_load"', () => { + expect(getViewEvent(0).loadingType).toEqual(ViewLoadingType.INITIAL_LOAD) + }) + + it('should collect view type as "route_change" after a route change', () => { + history.pushState({}, '', '/bar') + expect(getViewEvent(1).location.pathname).toEqual('/foo') + expect(getViewEvent(1).loadingType).toEqual(ViewLoadingType.INITIAL_LOAD) + + expect(getViewEvent(2).location.pathname).toEqual('/bar') + expect(getViewEvent(2).loadingType).toEqual(ViewLoadingType.ROUTE_CHANGE) + }) +}) + +describe('rum track loading time', () => { + let lifeCycle: LifeCycle + let getViewEvent: (index: number) => View + + beforeEach(() => { + jasmine.clock().install() + jasmine.clock().mockDate() + spyOn(performance, 'now').and.callFake(() => Date.now()) + ;({ lifeCycle, getViewEvent } = spyOnViews()) + }) + + afterEach(() => { + jasmine.clock().uninstall() + }) + + it('should have an undefined loading time if the load is complete without having any activity', () => { + jasmine.clock().tick(AFTER_PAGE_ACTIVITY_MAX_DURATION) + jasmine.clock().tick(THROTTLE_VIEW_UPDATE_PERIOD) + + expect(getViewEvent(1).loadingTime).toBeUndefined() + }) + + it('should have a loading time equal to the activity time if the load is complete with a unique activity', () => { + jasmine.clock().tick(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) + lifeCycle.notify(LifeCycleEventType.DOM_MUTATED) + jasmine.clock().tick(AFTER_PAGE_ACTIVITY_END_DELAY) + jasmine.clock().tick(THROTTLE_VIEW_UPDATE_PERIOD) + + expect(getViewEvent(1).loadingTime).toEqual(BEFORE_PAGE_ACTIVITY_VALIDATION_DELAY) + }) +}) + describe('rum view measures', () => { const FAKE_LONG_TASK = { entryType: 'longtask',