feat(core): more accurate network timestamps

ulixee · Oct 12, 2021 · c7a21ae · c7a21ae
1 parent 8c39d4b
commit c7a21ae
Show file tree

Hide file tree

Showing 10 changed files with 77 additions and 79 deletions.
diff --git a/core/lib/FrameEnvironment.ts b/core/lib/FrameEnvironment.ts
@@ -475,7 +475,7 @@ b) Use the UserProfile feature to set cookies for 1 or more domains before they'
     for (const [event, url, timestamp] of loadEvents) {
       const incomingStatus = pageStateToLoadStatus[event];
 
-      this.navigations.onLoadStatusChanged(incomingStatus, url, null, new Date(timestamp));
+      this.navigations.onLoadStatusChanged(incomingStatus, url, null, timestamp);
     }
 
     if (domChanges.length) {

diff --git a/core/lib/FrameNavigations.ts b/core/lib/FrameNavigations.ts
@@ -8,7 +8,6 @@ import { TypedEventEmitter } from '@ulixee/commons/lib/eventUtils';
 import { IBoundLog } from '@ulixee/commons/interfaces/ILog';
 import Log from '@ulixee/commons/lib/Logger';
 import { ILoadStatus, LoadStatus } from '@ulixee/hero-interfaces/Location';
-import * as moment from 'moment';
 import SessionState from './SessionState';
 
 export interface IFrameNavigationEvents {
@@ -94,7 +93,7 @@ export default class FrameNavigations extends TypedEventEmitter<IFrameNavigation
     // doesn't have any "contentful" items that are eligible (image, headers, divs, paragraphs that fill the page)
 
     // have contentPaintedDate date, but no load
-    const timeUntilReadyMs = moment().diff(contentPaintedDate ?? loadDate, 'milliseconds');
+    const timeUntilReadyMs = Date.now() - (contentPaintedDate ?? loadDate);
     return {
       isStable: timeUntilReadyMs >= 3e3,
       timeUntilReadyMs: Math.min(3e3, 3e3 - timeUntilReadyMs),
@@ -207,13 +206,18 @@ export default class FrameNavigations extends TypedEventEmitter<IFrameNavigation
     this.changeNavigationStatus(LoadStatus.HttpRequested, loaderId);
   }
 
-  public onHttpResponded(browserRequestId: string, url: string, loaderId: string): void {
+  public onHttpResponded(
+    browserRequestId: string,
+    url: string,
+    loaderId: string,
+    responseTime: number,
+  ): void {
     if (url === 'about:blank') return;
 
     const navigation = this.findMatchingNavigation(loaderId);
     navigation.finalUrl = url;
 
-    this.recordStatusChange(navigation, LoadStatus.HttpResponded);
+    this.recordStatusChange(navigation, LoadStatus.HttpResponded, responseTime);
   }
 
   public onResourceLoaded(resourceId: number, statusCode: number, error?: Error): void {
@@ -240,20 +244,16 @@ export default class FrameNavigations extends TypedEventEmitter<IFrameNavigation
       | LoadStatus.PaintingStable,
     url: string,
     loaderId: string,
-    statusChangeDate?: Date,
+    statusChangeDate?: number,
   ): void {
     if (url === 'about:blank') return;
-    // if this is a painting stable, it probably won't come from a loader event for the page
+    // if this is a painting stable, it won't come from a loader event for the page
     if (!loaderId) {
-      for (let i = this.history.length - 1; i >= 0; i -= 1) {
-        const nav = this.history[i];
-        if (nav && nav.finalUrl === url && nav.statusChanges.has(LoadStatus.HttpResponded)) {
-          loaderId = nav.loaderId;
-          break;
-        }
-      }
+      loaderId = this.findHistory(
+        nav => nav.finalUrl === url && nav.statusChanges.has(LoadStatus.HttpResponded),
+      )?.loaderId;
     }
-    this.changeNavigationStatus(incomingStatus, loaderId, statusChangeDate?.getTime());
+    this.changeNavigationStatus(incomingStatus, loaderId, statusChangeDate);
   }
 
   public updateNavigationReason(url: string, reason: NavigationReason): void {
@@ -284,18 +284,13 @@ export default class FrameNavigations extends TypedEventEmitter<IFrameNavigation
   }
 
   public getLastLoadedNavigation(): INavigation {
-    let navigation: INavigation;
-    for (let i = this.history.length - 1; i >= 0; i -= 1) {
-      navigation = this.history[i];
-      if (
-        navigation.statusChanges.has(LoadStatus.DomContentLoaded) &&
-        navigation.navigationReason !== 'inPage' &&
-        !!navigation.finalUrl
-      ) {
-        return navigation;
-      }
-    }
-    return this.top;
+    const lastDomLoadedNav = this.findHistory(
+      x =>
+        x.statusChanges.has(LoadStatus.DomContentLoaded) &&
+        x.navigationReason !== 'inPage' &&
+        !!x.finalUrl,
+    );
+    return lastDomLoadedNav ?? this.top;
   }
 
   private checkStoredNavigationReason(navigation: INavigation, url: string): void {
@@ -313,13 +308,8 @@ export default class FrameNavigations extends TypedEventEmitter<IFrameNavigation
     const navigation = this.top;
     if (!navigation) return undefined;
     if (loaderId && navigation.loaderId && navigation.loaderId !== loaderId) {
-      // find the right loader id
-      for (let i = this.history.length - 1; i >= 0; i -= 1) {
-        const nav = this.history[i];
-        if (nav && nav.loaderId === loaderId) {
-          return nav;
-        }
-      }
+      // still return the navigation if we can't find the loader
+      return this.findHistory(x => x.loaderId === loaderId) ?? navigation;
     }
     return navigation;
   }
@@ -334,18 +324,23 @@ export default class FrameNavigations extends TypedEventEmitter<IFrameNavigation
     }
 
     // find the right loader id
+    const navigation = this.findHistory(
+      x =>
+        x.loaderId === loaderId &&
+        !x.statusChanges.has(LoadStatus.HttpRedirected) &&
+        x.requestedUrl === requestedUrl,
+    );
+    if (navigation) {
+      navigation.finalUrl = finalUrl;
+      this.recordStatusChange(navigation, LoadStatus.HttpRedirected);
+      return navigation;
+    }
+  }
+
+  private findHistory(callback: (history: INavigation) => boolean): INavigation {
     for (let i = this.history.length - 1; i >= 0; i -= 1) {
       const navigation = this.history[i];
-      if (navigation && navigation.loaderId === loaderId) {
-        if (
-          !navigation.statusChanges.has(LoadStatus.HttpRedirected) &&
-          navigation.requestedUrl === requestedUrl
-        ) {
-          navigation.finalUrl = finalUrl;
-          this.recordStatusChange(navigation, LoadStatus.HttpRedirected);
-          return navigation;
-        }
-      }
+      if (callback(navigation)) return navigation;
     }
   }
 

diff --git a/core/lib/Tab.ts b/core/lib/Tab.ts
@@ -953,6 +953,7 @@ export default class Tab
         event.resource.browserRequestId,
         event.resource.responseUrl ?? event.resource.url?.href,
         event.loaderId,
+        event.resource.responseTime,
       );
     }
 
@@ -971,7 +972,7 @@ export default class Tab
         if (!request) continue;
         if (
           request.method === event.resource.method &&
-          Math.abs(request.timestamp - event.resource.requestTime.getTime()) < 500
+          Math.abs(request.timestamp - event.resource.requestTime) < 500
         ) {
           errorsMatchingUrl.splice(i, 1);
           this.sessionState.captureResourceRequestId(
@@ -1066,7 +1067,12 @@ export default class Tab
       return;
     }
 
-    frame.navigations.onHttpResponded(event.browserRequestId, event.url, event.loaderId);
+    frame.navigations.onHttpResponded(
+      event.browserRequestId,
+      event.url,
+      event.loaderId,
+      event.timestamp,
+    );
     this.session.mitmRequestSession.recordDocumentUserActivity(event.url);
   }
 

diff --git a/core/models/DomChangesTable.ts b/core/models/DomChangesTable.ts
@@ -72,10 +72,10 @@ export default class DomChangesTable extends SqliteTable<IDomChangeRecord> {
     return query.all(frameId, sinceCommandId ?? 0).map(DomChangesTable.inflateRecord);
   }
 
-  public getChangesSince(timestamp: number): IDomChangeRecord[] {
-    const query = this.db.prepare(`select * from ${this.tableName} where timestamp >= ?`);
+  public getChangesSinceNavigation(navigationId: number): IDomChangeRecord[] {
+    const query = this.db.prepare(`select * from ${this.tableName} where frameNavigationId >= ?`);
 
-    return query.all(timestamp).map(DomChangesTable.inflateRecord);
+    return query.all(navigationId).map(DomChangesTable.inflateRecord);
   }
 
   public static inflateRecord(record: IDomChangeRecord): IDomChangeRecord {

diff --git a/interfaces/IHttpResourceLoadDetails.ts b/interfaces/IHttpResourceLoadDetails.ts
@@ -22,7 +22,7 @@ export default interface IHttpResourceLoadDetails {
   dnsResolvedIp?: string;
   url: URL;
   method: string;
-  requestTime: Date;
+  requestTime: number;
   requestOriginalHeaders: IResourceHeaders;
   requestHeaders: IResourceHeaders;
   requestTrailers?: IResourceHeaders;
@@ -33,7 +33,7 @@ export default interface IHttpResourceLoadDetails {
   responseUrl?: string;
   responseOriginalHeaders?: IResourceHeaders;
   responseHeaders?: IResourceHeaders;
-  responseTime?: Date;
+  responseTime?: number;
   responseTrailers?: IResourceHeaders;
   resourceType?: ResourceType;
   browserRequestId?: string;

diff --git a/interfaces/IPuppetNetworkEvents.ts b/interfaces/IPuppetNetworkEvents.ts
@@ -16,6 +16,7 @@ export interface IPuppetNetworkEvents {
     location?: string;
     url?: string;
     loaderId: string;
+    timestamp: number;
   };
   'websocket-frame': {
     browserRequestId: string;

diff --git a/mitm/handlers/RequestSession.ts b/mitm/handlers/RequestSession.ts
@@ -44,7 +44,7 @@ export default class RequestSession extends TypedEventEmitter<IRequestSessionEve
     url: string;
     redirectedToUrl: string;
     redirectChain: string[];
-    responseTime: Date;
+    responseTime: number;
   }[] = [];
 
   public respondWithHttpErrorStacks = true;
@@ -80,8 +80,7 @@ export default class RequestSession extends TypedEventEmitter<IRequestSessionEve
 
     const redirect = this.requestedUrls.find(
       x =>
-        x.redirectedToUrl === resourceRedirect.url &&
-        resource.requestTime.getTime() - x.responseTime.getTime() < 5e3,
+        x.redirectedToUrl === resourceRedirect.url && resource.requestTime - x.responseTime < 5e3,
     );
     resource.isFromRedirect = !!redirect;
     if (redirect) {

diff --git a/mitm/lib/BrowserRequestMatcher.ts b/mitm/lib/BrowserRequestMatcher.ts
@@ -105,9 +105,7 @@ export default class BrowserRequestMatcher {
 
     if (resource && resource.browserRequestedPromise.isResolved && resource.browserRequestId) {
       // figure out how long ago this request was
-      const requestTimeDiff = Math.abs(
-        httpResourceLoad.requestTime.getTime() - resource.requestTime.getTime(),
-      );
+      const requestTimeDiff = Math.abs(httpResourceLoad.requestTime - resource.requestTime);
       if (requestTimeDiff > 5e3) resource = null;
     }
 
@@ -234,9 +232,12 @@ export default class BrowserRequestMatcher {
   }
 }
 
-function getHeaderDetails(
-  httpResourceLoad: IPuppetResourceRequest,
-): { origin: string; referer: string; secFetchDest: string; secFetchSite: string } {
+function getHeaderDetails(httpResourceLoad: IPuppetResourceRequest): {
+  origin: string;
+  referer: string;
+  secFetchDest: string;
+  secFetchSite: string;
+} {
   const origin = HeadersHandler.getRequestHeader<string>(httpResourceLoad, 'origin');
   const referer = HeadersHandler.getRequestHeader<string>(httpResourceLoad, 'referer');
   const secFetchDest = HeadersHandler.getRequestHeader<string>(httpResourceLoad, 'sec-fetch-dest');
@@ -251,7 +252,7 @@ interface IRequestedResource {
   secFetchSite: string;
   secFetchDest: string;
   referer: string;
-  requestTime: Date;
+  requestTime: number;
   browserRequestedPromise: IResolvablePromise<void>;
   tabId?: number;
   mitmResourceId?: number;

diff --git a/mitm/lib/MitmRequestContext.ts b/mitm/lib/MitmRequestContext.ts
@@ -41,13 +41,8 @@ export default class MitmRequestContext {
     >,
     responseCache: HttpResponseCache,
   ): IMitmRequestContext {
-    const {
-      isSSL,
-      proxyToClientResponse,
-      clientToProxyRequest,
-      requestSession,
-      isUpgrade,
-    } = params;
+    const { isSSL, proxyToClientResponse, clientToProxyRequest, requestSession, isUpgrade } =
+      params;
 
     const protocol = isUpgrade ? 'ws' : 'http';
     const expectedProtocol = `${protocol}${isSSL ? 's' : ''}:`;
@@ -95,7 +90,7 @@ export default class MitmRequestContext {
       requestOriginalHeaders: parseRawHeaders(clientToProxyRequest.rawHeaders),
       clientToProxyRequest,
       proxyToClientResponse,
-      requestTime: new Date(),
+      requestTime: Date.now(),
       protocol: (clientToProxyRequest.socket as TLSSocket)?.alpnProtocol || 'http/1.1',
       documentUrl: clientToProxyRequest.headers.origin as string,
       originType: this.getOriginType(url, requestHeaders),
@@ -148,7 +143,7 @@ export default class MitmRequestContext {
       proxyToClientResponse: null,
       serverToProxyResponseStream: null,
       proxyToServerRequest: null,
-      requestTime: new Date(),
+      requestTime: Date.now(),
       didBlockResource: false,
       cacheHandler: null,
       stateChanges: state,
@@ -168,7 +163,7 @@ export default class MitmRequestContext {
       headers: ctx.requestHeaders,
       method: ctx.method,
       postData: ctx.requestPostData,
-      timestamp: ctx.requestTime.getTime(),
+      timestamp: ctx.requestTime,
     } as IResourceRequest;
 
     const response = {
@@ -177,7 +172,7 @@ export default class MitmRequestContext {
       statusMessage: ctx.statusMessage,
       headers: ctx.responseHeaders,
       trailers: ctx.responseTrailers,
-      timestamp: ctx.responseTime?.getTime(),
+      timestamp: ctx.responseTime,
       browserServedFromCache: ctx.browserServedFromCache,
       browserLoadFailure: ctx.browserLoadFailure,
       remoteAddress: ctx.remoteAddress,
@@ -200,7 +195,7 @@ export default class MitmRequestContext {
       protocol: ctx.protocol,
       serverAlpn: ctx.proxyToServerMitmSocket?.alpn,
       didBlockResource: ctx.didBlockResource,
-      executionMillis: (ctx.responseTime ?? new Date()).getTime() - ctx.requestTime.getTime(),
+      executionMillis: (ctx.responseTime ?? Date.now()) - ctx.requestTime,
       isHttp2Push: ctx.isHttp2Push,
       browserBlockedReason: ctx.browserBlockedReason,
       browserCanceled: ctx.browserCanceled,
@@ -245,7 +240,7 @@ export default class MitmRequestContext {
     ctx.statusMessage = response.statusMessage;
 
     ctx.responseUrl = response.url;
-    ctx.responseTime = new Date();
+    ctx.responseTime = Date.now();
     ctx.serverToProxyResponse = response;
     ctx.responseOriginalHeaders = parseRawHeaders(response.rawHeaders);
     ctx.responseHeaders = HeadersHandler.cleanResponseHeaders(ctx, ctx.responseOriginalHeaders);
@@ -266,7 +261,7 @@ export default class MitmRequestContext {
     const headers = parseRawHeaders(rawHeaders);
     ctx.status = statusCode;
     ctx.originalStatus = statusCode;
-    ctx.responseTime = new Date();
+    ctx.responseTime = Date.now();
     ctx.serverToProxyResponse = response;
     ctx.responseOriginalHeaders = headers;
     ctx.responseHeaders = HeadersHandler.cleanResponseHeaders(ctx, headers);

diff --git a/puppet-chrome/lib/NetworkManager.ts b/puppet-chrome/lib/NetworkManager.ts
@@ -80,7 +80,7 @@ export class NetworkManager extends TypedEventEmitter<IPuppetNetworkEvents> {
   }
 
   public emit<
-    K extends (keyof IPuppetNetworkEvents & string) | (keyof IPuppetNetworkEvents & symbol)
+    K extends (keyof IPuppetNetworkEvents & string) | (keyof IPuppetNetworkEvents & symbol),
   >(eventType: K, event?: IPuppetNetworkEvents[K]): boolean {
     if (this.parentManager) {
       this.parentManager.emit(eventType, event);
@@ -214,7 +214,7 @@ export class NetworkManager extends TypedEventEmitter<IPuppetNetworkEvents> {
         isUpgrade: false,
         isHttp2Push: false,
         isServerHttp2: false,
-        requestTime: new Date(),
+        requestTime: Date.now(),
         protocol: null,
         hasUserGesture: false,
         documentUrl: networkRequest.request.headers.Referer,
@@ -269,7 +269,7 @@ export class NetworkManager extends TypedEventEmitter<IPuppetNetworkEvents> {
         isUpgrade: false,
         isHttp2Push: false,
         isServerHttp2: false,
-        requestTime: new Date(networkRequest.wallTime * 1e3),
+        requestTime: networkRequest.wallTime * 1e3,
         protocol: null,
         browserRequestId: networkRequest.requestId,
         resourceType: getResourceTypeForChromeValue(
@@ -415,7 +415,7 @@ export class NetworkManager extends TypedEventEmitter<IPuppetNetworkEvents> {
       resource.remoteAddress = `${response.remoteIPAddress}:${response.remotePort}`;
       resource.protocol = response.protocol;
       resource.responseUrl = response.url;
-      resource.responseTime = new Date();
+      resource.responseTime = response.responseTime;
       if (response.fromDiskCache) resource.browserServedFromCache = 'disk';
       if (response.fromServiceWorker) resource.browserServedFromCache = 'service-worker';
       if (response.fromPrefetchCache) resource.browserServedFromCache = 'prefetch';
@@ -440,6 +440,7 @@ export class NetworkManager extends TypedEventEmitter<IPuppetNetworkEvents> {
         location: response.headers.location,
         url: response.url,
         loaderId: event.loaderId,
+        timestamp: response.responseTime,
       });
     }
   }