[DNM] Full instrumentation

config/kibana.yml

@@ -5,6 +5,7 @@
 # Kibana is served by a back end server. This setting specifies the port to use.
 #server.port: 5601
 
+data.search.sessions.enabled: true
 # Specifies the address to which the Kibana server will bind. IP addresses and host names are both valid values.
 # The default is 'localhost', which usually means remote machines will not be able to connect.
 # To allow connections from remote users, set this parameter to a non-loopback address.

src/core/packages/http/browser-internal/src/fetch.ts

@@ -82,6 +82,8 @@ export class Fetch {
     const optionsWithPath = validateFetchArguments(pathOrOptions, options);
     const controller = new HttpInterceptController();
 
+    const mark = typeof pathOrOptions !== 'string' && pathOrOptions.mark;
+
     // We wrap the interception in a separate promise to ensure that when
     // a halt is called we do not resolve or reject, halting handling of the promise.
     return new Promise<TResponseBody | HttpResponse<TResponseBody>>(async (resolve, reject) => {
@@ -93,7 +95,7 @@ export class Fetch {
           controller
         );
         const initialResponse = interceptFetch(
-          this.fetchResponse.bind(this),
+          this.fetchResponse.bind(this, !!mark),
           interceptedOptions,
           this.interceptors,
           controller
@@ -164,12 +166,17 @@ export class Fetch {
   }
 
   private async fetchResponse(
+    mark: boolean,
     fetchOptions: HttpFetchOptionsWithPath
   ): Promise<HttpResponse<unknown>> {
     const request = this.createRequest(fetchOptions);
     let response: Response;
     let body = null;
 
+    if (mark) {
+      performance.mark('search_initiated');
+    }
+
     try {
       response = await window.fetch(request);
     } catch (err) {
@@ -189,6 +196,9 @@ export class Fetch {
         body = await response.arrayBuffer();
       } else {
         const text = await response.text();
+        if (mark) {
+          performance.mark('search_response_received');
+        }
 
         try {
           body = JSON.parse(text);
@@ -210,13 +220,14 @@ export class Fetch {
   private shorthand(method: string): HttpHandler {
     return <T = unknown>(
       pathOrOptions: string | HttpFetchOptionsWithPath,
-      options?: HttpFetchOptions
+      options?: HttpFetchOptions,
+      mark?: boolean
     ) => {
       const optionsWithPath: HttpFetchOptionsWithPath = validateFetchArguments(
         pathOrOptions,
         options
       );
-      return this.fetch<HttpResponse<T>>({ ...optionsWithPath, method });
+      return this.fetch<HttpResponse<T>>({ ...optionsWithPath, method, mark });
     };
   }
 }

src/core/packages/http/browser/src/types.ts

@@ -338,6 +338,7 @@ export interface HttpFetchOptionsWithPath extends HttpFetchOptions {
    * The path on the Kibana server to send the request to. Should not include the basePath.
    */
   path: string;
+  mark?: boolean;
 }
 
 /**
@@ -352,7 +353,8 @@ export interface HttpFetchOptionsWithPath extends HttpFetchOptions {
 export interface HttpHandler {
   <TResponseBody = unknown>(
     path: string,
-    options: HttpFetchOptions & { asResponse: true }
+    options: HttpFetchOptions & { asResponse: true },
+    mark?: boolean
   ): Promise<HttpResponse<TResponseBody>>;
 
   <TResponseBody = unknown>(options: HttpFetchOptionsWithPath & { asResponse: true }): Promise<

src/core/packages/rendering/server-internal/src/bootstrap/render_template.ts

@@ -159,6 +159,22 @@ if (window.__kbnStrictCsp__ && window.__kbnCspNotEnforced__) {
       detail: 'load_started',
     })
 
+    // Set up performance observer to log marks and measures as they happen
+    if (typeof PerformanceObserver !== 'undefined' && false) {
+      const observer = new PerformanceObserver((list) => {
+        const entries = list.getEntries();
+        entries.forEach((entry) => {
+          if (entry.entryType === 'mark') {
+            console.log(
+              \`Performance Mark: \${entry.name} at \${entry.startTime.toFixed(2)}ms\`,
+              entry.toJSON()
+            );
+          }
+        });
+      });
+      observer.observe({ entryTypes: ['mark', 'measure'] });
+    }
+
     load([
       ${jsDependencyPaths.map((path) => `'${path}'`).join(',')}
     ], function () {

src/platform/packages/shared/content-management/table_list_view_table/src/components/item_details.tsx

@@ -89,7 +89,9 @@ export function ItemDetails<T extends UserContentCommonSchema>({
         {/* eslint-disable-next-line  @elastic/eui/href-or-on-click */}
         <EuiLink
           href={getDetailViewLink?.(item)}
-          onClick={onClickTitleHandler}
+          onClick={() => {
+            performance.mark('navigate_to_dashboard');
+          }}
           data-test-subj={`${id}ListingTitleLink-${item.attributes.title.split(' ').join('-')}`}
         >
           <EuiHighlight highlightAll search={escapeRegExp(searchTerm)}>

src/platform/plugins/shared/chart_expressions/expression_xy/public/components/xy_chart.tsx

@@ -301,6 +301,8 @@ export function XYChart({
   const onRenderChange = useCallback(
     (isRendered: boolean = true) => {
       if (isRendered) {
+        performance.mark('render_complete');
+
         renderComplete();
       }
     },

src/platform/plugins/shared/chart_expressions/expression_xy/public/expression_renderers/xy_chart_renderer.tsx

@@ -313,5 +313,7 @@ export const getXyChartRenderer = ({
       </KibanaRenderContextProvider>,
       domNode
     );
+
+    performance.mark('charts_lib_invoked');
   },
 });

src/platform/plugins/shared/dashboard/public/dashboard_app/dashboard_app.tsx

@@ -257,7 +257,25 @@ export function DashboardApp({
         locator={locator}
         onApiAvailable={(dashboard) => {
           if (dashboard && !dashboardApi) {
+            // performance.mark('setDashboardApi-start');
             setDashboardApi(dashboard);
+            // performance.mark('setDashboardApi-end');
+            // performance.measure(
+            //   'setDashboardApi-execution',
+            //   'setDashboardApi-start',
+            //   'setDashboardApi-end'
+            // );
+
+            const setDashboardApiMeasure = performance.getEntriesByName(
+              'setDashboardApi-execution'
+            )[0];
+            if (setDashboardApiMeasure) {
+              // eslint-disable-next-line no-console
+              console.log(
+                `setDashboardApi execution took: ${setDashboardApiMeasure.duration.toFixed(2)}ms`
+              );
+            }
+
             if (expandedPanelId) {
               dashboard?.expandPanel(expandedPanelId);
             }

src/platform/plugins/shared/dashboard/public/dashboard_app/dashboard_router.tsx

@@ -96,6 +96,7 @@ export async function mountApp({
   const renderDashboard = (
     routeProps: RouteComponentProps<{ id?: string; expandedPanelId?: string }>
   ) => {
+    performance.mark('dashboard_render_initiated');
     const routeParams = parse(routeProps.history.location.search);
     if (routeParams.embed === 'true' && !globalEmbedSettings) {
       globalEmbedSettings = getDashboardEmbedSettings(routeParams);

src/platform/plugins/shared/data/common/search/expressions/esql.ts

@@ -173,6 +173,8 @@ export const getEsqlFn = ({ getStartDependencies }: EsqlFnArguments) => {
       },
       { abortSignal, inspectorAdapters, getKibanaRequest, getSearchSessionId }
     ) {
+      performance.mark('requester_fn');
+
       return defer(() =>
         getStartDependencies(() => {
           const request = getKibanaRequest?.();

src/platform/plugins/shared/data/public/search/expressions/esaggs.ts

@@ -47,6 +47,7 @@ export function getFunctionDefinition({
       args,
       { inspectorAdapters, abortSignal, getSearchSessionId, getExecutionContext, getSearchContext }
     ) {
+      performance.mark('requester_fn');
       return defer(async () => {
         const [{ aggs, indexPatterns, searchSource, getNow }, { handleEsaggsRequest }] =
           await Promise.all([getStartDependencies(), import('../../../common/search/expressions')]);

src/platform/plugins/shared/data/public/search/search_interceptor/search_interceptor.ts

@@ -288,7 +288,8 @@ export class SearchInterceptor {
   private runSearch$(
     { id, ...request }: IKibanaSearchRequest,
     options: IAsyncSearchOptions,
-    searchAbortController: SearchAbortController
+    searchAbortController: SearchAbortController,
+    mark: boolean = false
   ) {
     const { sessionId, strategy } = options;
 
@@ -304,7 +305,8 @@ export class SearchInterceptor {
           ...this.deps.session.getSearchOptions(sessionId),
           abortSignal: searchAbortController.getSignal(),
           isSearchStored,
-        }
+        },
+        mark
       )
         .then((result) => {
           afterPoll({ isSearchStored: result.isStored ?? false });
@@ -439,7 +441,8 @@ export class SearchInterceptor {
    */
   private runSearch(
     request: IKibanaSearchRequest,
-    options?: ISearchOptions
+    options?: ISearchOptions,
+    mark: boolean = false
   ): Promise<IKibanaSearchResponse> {
     const { abortSignal } = options || {};
 
@@ -460,7 +463,8 @@ export class SearchInterceptor {
               strategy === undefined, // undefined strategy is treated as enhanced ES
           }),
           asResponse: true,
-        }
+        },
+        mark
       )
       .then((rawResponse) => {
         const warning = rawResponse.response?.headers.get('warning');
@@ -534,7 +538,8 @@ export class SearchInterceptor {
   private getSearchResponse$(
     request: IKibanaSearchRequest,
     options: IAsyncSearchOptions,
-    requestHash?: string
+    requestHash?: string,
+    mark: boolean = false
   ) {
     const cached = requestHash ? this.responseCache.get(requestHash) : undefined;
 
@@ -544,7 +549,8 @@ export class SearchInterceptor {
     // Create a new abort signal if one was not passed. This fake signal will never be aborted,
     // So the underlaying search will not be aborted, even if the other consumers abort.
     searchAbortController.addAbortSignal(options.abortSignal ?? new AbortController().signal);
-    const response$ = cached?.response$ || this.runSearch$(request, options, searchAbortController);
+    const response$ =
+      cached?.response$ || this.runSearch$(request, options, searchAbortController, mark);
 
     if (requestHash && !this.responseCache.has(requestHash)) {
       this.responseCache.set(requestHash, {
@@ -568,7 +574,11 @@ export class SearchInterceptor {
    * @options
    * @returns `Observable` emitting the search response or an error.
    */
-  public search({ id, ...request }: IKibanaSearchRequest, options: IAsyncSearchOptions = {}) {
+  public search(
+    { id, ...request }: IKibanaSearchRequest,
+    options: IAsyncSearchOptions = {},
+    mark: boolean = false
+  ) {
     const searchOptions = {
       ...options,
     };
@@ -583,7 +593,8 @@ export class SearchInterceptor {
         const { searchAbortController, response$ } = this.getSearchResponse$(
           request,
           searchOptions,
-          requestHash
+          requestHash,
+          mark
         );
 
         this.pendingCount$.next(this.pendingCount$.getValue() + 1);

src/platform/plugins/shared/data/public/search/search_service.ts

@@ -231,7 +231,7 @@ export class SearchService implements Plugin<ISearchSetup, ISearchStart> {
     const { http, uiSettings, chrome, application, notifications, ...startServices } = coreStart;
 
     const search = ((request, options = {}) => {
-      return this.searchInterceptor.search(request, options);
+      return this.searchInterceptor.search(request, options, true);
     }) as ISearchGeneric;
 
     const loadingCount$ = new BehaviorSubject(0);

src/platform/plugins/shared/data_views/server/fetcher/index_patterns_fetcher.ts

@@ -102,6 +102,8 @@ export class IndexPatternsFetcher {
 
     const expandWildcards = allowHidden ? 'all' : 'open';
 
+    performance.mark('getFieldsForWildcard:start');
+
     const fieldCapsResponse = await getFieldCapabilities({
       callCluster: this.elasticsearchClient,
       uiSettingsClient: this.uiSettingsClient,
@@ -120,6 +122,8 @@ export class IndexPatternsFetcher {
       abortSignal,
     });
 
+    performance.mark('getFieldsForWildcard:getFieldCapsEnd');
+
     if (this.rollupsEnabled && type === DataViewType.ROLLUP && rollupIndex) {
       const rollupFields: FieldDescriptor[] = [];
       const capabilities = getCapabilitiesForRollupIndices(
@@ -152,6 +156,29 @@ export class IndexPatternsFetcher {
         indices: fieldCapsResponse.indices,
       };
     }
+
+    performance.mark('getFieldsForWildcard:end');
+
+    // add measures and print all measures
+    performance.measure('getFieldsForWildcard:total', 'getFieldsForWildcard:start');
+    performance.measure(
+      'getFieldsForWildcard:getFieldCaps',
+      'getFieldsForWildcard:start',
+      'getFieldsForWildcard:getFieldCapsEnd'
+    );
+    performance.measure(
+      'getFieldsForWildcard:rollupProcessing',
+      'getFieldsForWildcard:getFieldCapsEnd',
+      'getFieldsForWildcard:end'
+    );
+
+    performance.getEntriesByType('measure').forEach((m) => {
+      // eslint-disable-next-line no-console
+      console.log(`${m.name}: ${m.duration}`);
+    });
+    performance.clearMarks();
+    performance.clearMeasures();
+
     return fieldCapsResponse;
   }
 

src/platform/plugins/shared/data_views/server/fetcher/lib/field_capabilities/field_capabilities.ts

@@ -60,7 +60,9 @@ export async function getFieldCapabilities(params: FieldCapabilitiesParams) {
     abortSignal,
   } = params;
 
+  performance.mark('getFieldCapabilities:start');
   const excludedTiers = await uiSettingsClient?.get<string>(DATA_VIEWS_FIELDS_EXCLUDED_TIERS);
+  performance.mark('getFieldCapabilities:uiSettingsEnd');
   const esFieldCaps = await callFieldCapsApi({
     callCluster,
     indices,
@@ -73,7 +75,10 @@ export async function getFieldCapabilities(params: FieldCapabilitiesParams) {
     runtimeMappings,
     abortSignal,
   });
-  const fieldCapsArr = readFieldCapsResponse(esFieldCaps.body);
+  performance.mark('getFieldCapabilities:responseEnd');
+  const fieldCapsArr = await readFieldCapsResponse(esFieldCaps.body);
+  performance.mark('getFieldCapabilities:readEnd');
+
   const fieldsFromFieldCapsByName = keyBy(fieldCapsArr, 'name');
 
   const allFieldsUnsorted = Object.keys(fieldsFromFieldCapsByName)
@@ -105,6 +110,30 @@ export async function getFieldCapabilities(params: FieldCapabilitiesParams) {
     )
     .map(mergeOverrides);
 
+  performance.mark('getFieldCapabilities:allFieldsCollectedEnd');
+
+  // add measures and print all measures
+  performance.measure(
+    'getFieldCapabilities:uiSettings',
+    'getFieldCapabilities:start',
+    'getFieldCapabilities:uiSettingsEnd'
+  );
+  performance.measure(
+    'getFieldCapabilities:response',
+    'getFieldCapabilities:uiSettingsEnd',
+    'getFieldCapabilities:responseEnd'
+  );
+  performance.measure(
+    'getFieldCapabilities:read',
+    'getFieldCapabilities:responseEnd',
+    'getFieldCapabilities:readEnd'
+  );
+  performance.measure(
+    'getFieldCapabilities:allFieldsCollected',
+    'getFieldCapabilities:readEnd',
+    'getFieldCapabilities:allFieldsCollectedEnd'
+  );
+
   return {
     fields: sortBy(allFieldsUnsorted, 'name'),
     indices: esFieldCaps.body.indices as string[],