Display Kibana overall status in the logs and have FTR wait for green status before running tests (#92568)

* add licensing plugin status

* simplify log message

* review comments

packages/kbn-test/src/functional_tests/lib/run_kibana_server.js

@@ -38,7 +38,7 @@ export async function runKibanaServer({ procs, config, options }) {
       ...extendNodeOptions(installDir),
     },
     cwd: installDir || KIBANA_ROOT,
-    wait: /http server running/,
+    wait: /Kibana is now available/,
   });
 }
 

packages/kbn-test/src/functional_tests/tasks.js

@@ -95,8 +95,6 @@ export async function runTests(options) {
       try {
         es = await runElasticsearch({ config, options: opts });
         await runKibanaServer({ procs, config, options: opts });
-        // workaround until https://github.com/elastic/kibana/issues/89828 is addressed
-        await delay(5000);
         await runFtr({ configPath, options: opts });
       } finally {
         try {
@@ -162,7 +160,3 @@ async function silence(log, milliseconds) {
     )
     .toPromise();
 }
-
-async function delay(ms) {
-  await new Promise((resolve) => setTimeout(resolve, ms));
-}

src/core/server/server.ts

@@ -269,6 +269,7 @@ export class Server {
       plugins: mapToObject(pluginsStart.contracts),
     });
 
+    this.status.start();
     await this.http.start();
 
     startTransaction?.end();

src/core/server/status/log_overall_status.test.ts

@@ -0,0 +1,103 @@
+/*
+ * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
+ * or more contributor license agreements. Licensed under the Elastic License
+ * 2.0 and the Server Side Public License, v 1; you may not use this file except
+ * in compliance with, at your election, the Elastic License 2.0 or the Server
+ * Side Public License, v 1.
+ */
+
+import { TestScheduler } from 'rxjs/testing';
+import { ServiceStatus, ServiceStatusLevels } from './types';
+import { getOverallStatusChanges } from './log_overall_status';
+
+const getTestScheduler = () =>
+  new TestScheduler((actual, expected) => {
+    expect(actual).toEqual(expected);
+  });
+
+const createStatus = (parts: Partial<ServiceStatus> = {}): ServiceStatus => ({
+  level: ServiceStatusLevels.available,
+  summary: 'summary',
+  ...parts,
+});
+
+describe('getOverallStatusChanges', () => {
+  it('emits an initial message after first overall$ emission', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const overall$ = hot<ServiceStatus>('--a', {
+        a: createStatus(),
+      });
+      const stop$ = hot<void>('');
+      const expected = '--a';
+
+      expectObservable(getOverallStatusChanges(overall$, stop$)).toBe(expected, {
+        a: 'Kibana is now available',
+      });
+    });
+  });
+
+  it('emits a new message every time the status level changes', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const overall$ = hot<ServiceStatus>('--a--b', {
+        a: createStatus({
+          level: ServiceStatusLevels.degraded,
+        }),
+        b: createStatus({
+          level: ServiceStatusLevels.available,
+        }),
+      });
+      const stop$ = hot<void>('');
+      const expected = '--a--b';
+
+      expectObservable(getOverallStatusChanges(overall$, stop$)).toBe(expected, {
+        a: 'Kibana is now degraded',
+        b: 'Kibana is now available (was degraded)',
+      });
+    });
+  });
+
+  it('does not emit when the status stays the same', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const overall$ = hot<ServiceStatus>('--a--b--c', {
+        a: createStatus({
+          level: ServiceStatusLevels.degraded,
+          summary: 'summary 1',
+        }),
+        b: createStatus({
+          level: ServiceStatusLevels.degraded,
+          summary: 'summary 2',
+        }),
+        c: createStatus({
+          level: ServiceStatusLevels.available,
+          summary: 'summary 2',
+        }),
+      });
+      const stop$ = hot<void>('');
+      const expected = '--a-----b';
+
+      expectObservable(getOverallStatusChanges(overall$, stop$)).toBe(expected, {
+        a: 'Kibana is now degraded',
+        b: 'Kibana is now available (was degraded)',
+      });
+    });
+  });
+
+  it('stops emitting once `stop$` emits', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const overall$ = hot<ServiceStatus>('--a--b', {
+        a: createStatus({
+          level: ServiceStatusLevels.degraded,
+        }),
+        b: createStatus({
+          level: ServiceStatusLevels.available,
+        }),
+      });
+      const stop$ = hot<void>('----(s|)');
+      const expected = '--a-|';
+
+      expectObservable(getOverallStatusChanges(overall$, stop$)).toBe(expected, {
+        a: 'Kibana is now degraded',
+      });
+    });
+  });
+});

src/core/server/status/log_overall_status.ts

@@ -0,0 +1,31 @@
+/*
+ * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
+ * or more contributor license agreements. Licensed under the Elastic License
+ * 2.0 and the Server Side Public License, v 1; you may not use this file except
+ * in compliance with, at your election, the Elastic License 2.0 or the Server
+ * Side Public License, v 1.
+ */
+
+import { Observable } from 'rxjs';
+import { distinctUntilChanged, pairwise, startWith, takeUntil, map } from 'rxjs/operators';
+import { ServiceStatus } from './types';
+
+export const getOverallStatusChanges = (
+  overall$: Observable<ServiceStatus>,
+  stop$: Observable<void>
+) => {
+  return overall$.pipe(
+    takeUntil(stop$),
+    distinctUntilChanged((previous, next) => {
+      return previous.level.toString() === next.level.toString();
+    }),
+    startWith(undefined),
+    pairwise(),
+    map(([oldStatus, newStatus]) => {
+      if (oldStatus) {
+        return `Kibana is now ${newStatus!.level.toString()} (was ${oldStatus!.level.toString()})`;
+      }
+      return `Kibana is now ${newStatus!.level.toString()}`;
+    })
+  );
+};

src/core/server/status/status_service.ts

@@ -6,7 +6,7 @@
  * Side Public License, v 1.
  */
 
-import { Observable, combineLatest, Subscription } from 'rxjs';
+import { Observable, combineLatest, Subscription, Subject } from 'rxjs';
 import { map, distinctUntilChanged, shareReplay, take, debounceTime } from 'rxjs/operators';
 import { isDeepStrictEqual } from 'util';
 
@@ -25,6 +25,7 @@ import { config, StatusConfigType } from './status_config';
 import { ServiceStatus, CoreStatus, InternalStatusServiceSetup } from './types';
 import { getSummaryStatus } from './get_summary_status';
 import { PluginsStatusService } from './plugins_status';
+import { getOverallStatusChanges } from './log_overall_status';
 
 interface SetupDeps {
   elasticsearch: Pick<InternalElasticsearchServiceSetup, 'status$'>;
@@ -38,7 +39,9 @@ interface SetupDeps {
 export class StatusService implements CoreService<InternalStatusServiceSetup> {
   private readonly logger: Logger;
   private readonly config$: Observable<StatusConfigType>;
+  private readonly stop$ = new Subject<void>();
 
+  private overall$?: Observable<ServiceStatus>;
   private pluginsStatus?: PluginsStatusService;
   private overallSubscription?: Subscription;
 
@@ -59,10 +62,7 @@ export class StatusService implements CoreService<InternalStatusServiceSetup> {
     const core$ = this.setupCoreStatus({ elasticsearch, savedObjects });
     this.pluginsStatus = new PluginsStatusService({ core$, pluginDependencies });
 
-    const overall$: Observable<ServiceStatus> = combineLatest([
-      core$,
-      this.pluginsStatus.getAll$(),
-    ]).pipe(
+    this.overall$ = combineLatest([core$, this.pluginsStatus.getAll$()]).pipe(
       // Prevent many emissions at once from dependency status resolution from making this too noisy
       debounceTime(500),
       map(([coreStatus, pluginsStatus]) => {
@@ -78,7 +78,7 @@ export class StatusService implements CoreService<InternalStatusServiceSetup> {
     );
 
     // Create an unused subscription to ensure all underlying lazy observables are started.
-    this.overallSubscription = overall$.subscribe();
+    this.overallSubscription = this.overall$.subscribe();
 
     const router = http.createRouter('');
     registerStatusRoute({
@@ -91,7 +91,7 @@ export class StatusService implements CoreService<InternalStatusServiceSetup> {
       },
       metrics,
       status: {
-        overall$,
+        overall$: this.overall$,
         plugins$: this.pluginsStatus.getAll$(),
         core$,
       },
@@ -99,7 +99,7 @@ export class StatusService implements CoreService<InternalStatusServiceSetup> {
 
     return {
       core$,
-      overall$,
+      overall$: this.overall$,
       plugins: {
         set: this.pluginsStatus.set.bind(this.pluginsStatus),
         getDependenciesStatus$: this.pluginsStatus.getDependenciesStatus$.bind(this.pluginsStatus),
@@ -109,9 +109,19 @@ export class StatusService implements CoreService<InternalStatusServiceSetup> {
     };
   }
 
-  public start() {}
+  public start() {
+    if (!this.overall$) {
+      throw new Error('cannot call `start` before `setup`');
+    }
+    getOverallStatusChanges(this.overall$, this.stop$).subscribe((message) => {
+      this.logger.info(message);
+    });
+  }
 
   public stop() {
+    this.stop$.next();
+    this.stop$.complete();
+
     if (this.overallSubscription) {
       this.overallSubscription.unsubscribe();
       this.overallSubscription = undefined;

x-pack/plugins/apm/e2e/run-e2e.sh

@@ -147,7 +147,7 @@ $WAIT_ON_BIN -i 500 -w 500 http-get://admin:changeme@localhost:$KIBANA_PORT/api/
 ## Workaround to wait for the http server running
 ## See: https://github.com/elastic/kibana/issues/66326
 if [ -e kibana.log ] ; then
-    grep -m 1 "http server running" <(tail -f -n +1 kibana.log)
+    grep -m 1 "Kibana is now available" <(tail -f -n +1 kibana.log)
     echo "✅ Kibana server running..."
     grep -m 1 "bundles compiled successfully" <(tail -f -n +1 kibana.log)
     echo "✅ Kibana bundles have been compiled..."

x-pack/plugins/licensing/server/plugin.ts

@@ -32,6 +32,7 @@ import { FeatureUsageService } from './services';
 import { LicenseConfigType } from './licensing_config';
 import { createRouteHandlerContext } from './licensing_route_handler_context';
 import { createOnPreResponseHandler } from './on_pre_response_handler';
+import { getPluginStatus$ } from './plugin_status';
 
 function normalizeServerLicense(license: RawLicense): PublicLicense {
   return {
@@ -80,7 +81,7 @@ function sign({
  * current Kibana instance.
  */
 export class LicensingPlugin implements Plugin<LicensingPluginSetup, LicensingPluginStart, {}, {}> {
-  private stop$ = new Subject();
+  private stop$ = new Subject<void>();
   private readonly logger: Logger;
   private readonly config: LicenseConfigType;
   private loggingSubscription?: Subscription;
@@ -127,6 +128,8 @@ export class LicensingPlugin implements Plugin<LicensingPluginSetup, LicensingPl
       pollingFrequency.asMilliseconds()
     );
 
+    core.status.set(getPluginStatus$(license$, this.stop$.asObservable()));
+
     core.http.registerRouteHandlerContext(
       'licensing',
       createRouteHandlerContext(license$, core.getStartServices)

x-pack/plugins/licensing/server/plugin_status.test.ts

@@ -0,0 +1,114 @@
+/*
+ * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
+ * or more contributor license agreements. Licensed under the Elastic License
+ * 2.0; you may not use this file except in compliance with the Elastic License
+ * 2.0.
+ */
+
+import { TestScheduler } from 'rxjs/testing';
+import { ServiceStatusLevels } from '../../../../src/core/server';
+import { licenseMock } from '../common/licensing.mock';
+import { getPluginStatus$ } from './plugin_status';
+import { ILicense } from '../common/types';
+
+const getTestScheduler = () =>
+  new TestScheduler((actual, expected) => {
+    expect(actual).toEqual(expected);
+  });
+
+const degradedStatus = {
+  level: ServiceStatusLevels.degraded,
+  summary: expect.any(String),
+};
+const availableStatus = {
+  level: ServiceStatusLevels.available,
+  summary: expect.any(String),
+};
+const unavailableStatus = {
+  level: ServiceStatusLevels.unavailable,
+  summary: expect.any(String),
+};
+
+describe('getPluginStatus$', () => {
+  it('emits an initial `degraded` status', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const license$ = hot<ILicense>('|');
+      const stop$ = hot<void>('');
+      const expected = '(a|)';
+
+      expectObservable(getPluginStatus$(license$, stop$)).toBe(expected, {
+        a: degradedStatus,
+      });
+    });
+  });
+
+  it('emits an `available` status once the license emits', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const license$ = hot<ILicense>('--a', {
+        a: licenseMock.createLicenseMock(),
+      });
+      const stop$ = hot<void>('');
+      const expected = 'a-b';
+
+      expectObservable(getPluginStatus$(license$, stop$)).toBe(expected, {
+        a: degradedStatus,
+        b: availableStatus,
+      });
+    });
+  });
+
+  it('emits an `unavailable` status if the license emits an error', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const errorLicense = licenseMock.createLicenseMock();
+      errorLicense.error = 'some-error';
+
+      const license$ = hot<ILicense>('--a', {
+        a: errorLicense,
+      });
+      const stop$ = hot<void>('');
+      const expected = 'a-b';
+
+      expectObservable(getPluginStatus$(license$, stop$)).toBe(expected, {
+        a: degradedStatus,
+        b: unavailableStatus,
+      });
+    });
+  });
+
+  it('can emit `available` after `unavailable`', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const errorLicense = licenseMock.createLicenseMock();
+      errorLicense.error = 'some-error';
+      const validLicense = licenseMock.createLicenseMock();
+
+      const license$ = hot<ILicense>('--a--b', {
+        a: errorLicense,
+        b: validLicense,
+      });
+      const stop$ = hot<void>('');
+      const expected = 'a-b--c';
+
+      expectObservable(getPluginStatus$(license$, stop$)).toBe(expected, {
+        a: degradedStatus,
+        b: unavailableStatus,
+        c: availableStatus,
+      });
+    });
+  });
+
+  it('closes when `stop$` emits', () => {
+    getTestScheduler().run(({ expectObservable, hot }) => {
+      const license$ = hot<ILicense>('--a--b', {
+        a: licenseMock.createLicenseMock(),
+        b: licenseMock.createLicenseMock(),
+      });
+      const stop$ = hot<void>('----a', { a: undefined });
+      const expected = 'a-b-|';
+
+      expectObservable(getPluginStatus$(license$, stop$)).toBe(expected, {
+        a: degradedStatus,
+        b: availableStatus,
+      });
+    });
+  });
+});

x-pack/plugins/licensing/server/plugin_status.ts

@@ -0,0 +1,39 @@
+/*
+ * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
+ * or more contributor license agreements. Licensed under the Elastic License
+ * 2.0; you may not use this file except in compliance with the Elastic License
+ * 2.0.
+ */
+
+import { Observable } from 'rxjs';
+import { takeUntil, startWith, map } from 'rxjs/operators';
+import { ServiceStatus, ServiceStatusLevels } from '../../../../src/core/server';
+import { ILicense } from '../common/types';
+
+export const getPluginStatus$ = (
+  license$: Observable<ILicense>,
+  stop$: Observable<void>
+): Observable<ServiceStatus> => {
+  return license$.pipe(
+    startWith(undefined),
+    takeUntil(stop$),
+    map((license) => {
+      if (license) {
+        if (license.error) {
+          return {
+            level: ServiceStatusLevels.unavailable,
+            summary: 'Error fetching license',
+          };
+        }
+        return {
+          level: ServiceStatusLevels.available,
+          summary: 'License fetched',
+        };
+      }
+      return {
+        level: ServiceStatusLevels.degraded,
+        summary: 'License not fetched yet',
+      };
+    })
+  );
+};