Report audit logging feature usage (#87457)

* Report audit logging feature usage * Fix mock * Added unref
elastic · Jan 6, 2021 · 2b5071f · 2b5071f
1 parent c57efbb
commit 2b5071f
Show file tree

Hide file tree

Showing 7 changed files with 134 additions and 16 deletions.
diff --git a/x-pack/plugins/security/common/licensing/index.mock.ts b/x-pack/plugins/security/common/licensing/index.mock.ts
@@ -5,14 +5,14 @@
  */
 
 import { of } from 'rxjs';
-import { SecurityLicense } from '.';
+import { SecurityLicense, SecurityLicenseFeatures } from '.';
 
 export const licenseMock = {
-  create: (): jest.Mocked<SecurityLicense> => ({
+  create: (features?: Partial<SecurityLicenseFeatures>): jest.Mocked<SecurityLicense> => ({
     isLicenseAvailable: jest.fn(),
     isEnabled: jest.fn().mockReturnValue(true),
     getType: jest.fn().mockReturnValue('basic'),
     getFeatures: jest.fn(),
-    features$: of(),
+    features$: features ? of(features as SecurityLicenseFeatures) : of(),
   }),
 };
diff --git a/x-pack/plugins/security/server/audit/audit_service.test.ts b/x-pack/plugins/security/server/audit/audit_service.test.ts
@@ -3,7 +3,12 @@
  * or more contributor license agreements. Licensed under the Elastic License;
  * you may not use this file except in compliance with the Elastic License.
  */
-import { AuditService, filterEvent, createLoggingConfig } from './audit_service';
+import {
+  AuditService,
+  filterEvent,
+  createLoggingConfig,
+  RECORD_USAGE_INTERVAL,
+} from './audit_service';
 import { AuditEvent, EventCategory, EventType, EventOutcome } from './audit_events';
 import {
   coreMock,
@@ -16,6 +21,8 @@ import { ConfigSchema, ConfigType } from '../config';
 import { SecurityLicenseFeatures } from '../../common/licensing';
 import { BehaviorSubject, Observable, of } from 'rxjs';
 
+jest.useFakeTimers();
+
 const createConfig = (settings: Partial<ConfigType['audit']>) => {
   return ConfigSchema.validate(settings);
 };
@@ -28,36 +35,41 @@ const http = httpServiceMock.createSetupContract();
 const getCurrentUser = jest.fn().mockReturnValue({ username: 'jdoe', roles: ['admin'] });
 const getSpaceId = jest.fn().mockReturnValue('default');
 const getSID = jest.fn().mockResolvedValue('SESSION_ID');
+const recordAuditLoggingUsage = jest.fn();
 
 beforeEach(() => {
   logger.info.mockClear();
   logging.configure.mockClear();
+  recordAuditLoggingUsage.mockClear();
   http.registerOnPostAuth.mockClear();
 });
 
 describe('#setup', () => {
   it('returns the expected contract', () => {
-    const auditService = new AuditService(logger);
+    const audit = new AuditService(logger);
     expect(
-      auditService.setup({
+      audit.setup({
         license,
         config,
         logging,
         http,
         getCurrentUser,
         getSpaceId,
         getSID,
+        recordAuditLoggingUsage,
       })
     ).toMatchInlineSnapshot(`
       Object {
         "asScoped": [Function],
         "getLogger": [Function],
       }
     `);
+    audit.stop();
   });
 
   it('configures logging correctly when using ecs logger', async () => {
-    new AuditService(logger).setup({
+    const audit = new AuditService(logger);
+    audit.setup({
       license,
       config: {
         enabled: true,
@@ -73,40 +85,99 @@ describe('#setup', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
     expect(logging.configure).toHaveBeenCalledWith(expect.any(Observable));
+    audit.stop();
+  });
+
+  it('records feature usage correctly when using ecs logger', async () => {
+    const audit = new AuditService(logger);
+    audit.setup({
+      license: licenseMock.create({
+        allowAuditLogging: true,
+      }),
+      config: {
+        enabled: true,
+        appender: {
+          kind: 'console',
+          layout: {
+            kind: 'pattern',
+          },
+        },
+      },
+      logging,
+      http,
+      getCurrentUser,
+      getSpaceId,
+      getSID,
+      recordAuditLoggingUsage,
+    });
+    expect(recordAuditLoggingUsage).toHaveBeenCalledTimes(1);
+    jest.advanceTimersByTime(RECORD_USAGE_INTERVAL);
+    expect(recordAuditLoggingUsage).toHaveBeenCalledTimes(2);
+    jest.advanceTimersByTime(RECORD_USAGE_INTERVAL);
+    expect(recordAuditLoggingUsage).toHaveBeenCalledTimes(3);
+    audit.stop();
+  });
+
+  it('does not record feature usage when disabled', async () => {
+    const audit = new AuditService(logger);
+    audit.setup({
+      license,
+      config: {
+        enabled: false,
+      },
+      logging,
+      http,
+      getCurrentUser,
+      getSpaceId,
+      getSID,
+      recordAuditLoggingUsage,
+    });
+    expect(recordAuditLoggingUsage).not.toHaveBeenCalled();
+    jest.advanceTimersByTime(RECORD_USAGE_INTERVAL);
+    expect(recordAuditLoggingUsage).not.toHaveBeenCalled();
+    jest.advanceTimersByTime(RECORD_USAGE_INTERVAL);
+    expect(recordAuditLoggingUsage).not.toHaveBeenCalled();
+    audit.stop();
   });
 
   it('registers post auth hook', () => {
-    new AuditService(logger).setup({
+    const audit = new AuditService(logger);
+    audit.setup({
       license,
       config,
       logging,
       http,
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
     expect(http.registerOnPostAuth).toHaveBeenCalledWith(expect.any(Function));
+    audit.stop();
   });
 });
 
 describe('#asScoped', () => {
   it('logs event enriched with meta data', async () => {
-    const audit = new AuditService(logger).setup({
+    const audit = new AuditService(logger);
+    const auditSetup = audit.setup({
       license,
       config,
       logging,
       http,
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
     const request = httpServerMock.createKibanaRequest({
       kibanaRequestState: { requestId: 'REQUEST_ID', requestUuid: 'REQUEST_UUID' },
     });
 
-    await audit.asScoped(request).log({ message: 'MESSAGE', event: { action: 'ACTION' } });
+    await auditSetup.asScoped(request).log({ message: 'MESSAGE', event: { action: 'ACTION' } });
     expect(logger.info).toHaveBeenCalledWith('MESSAGE', {
       ecs: { version: '1.6.0' },
       event: { action: 'ACTION' },
@@ -115,10 +186,12 @@ describe('#asScoped', () => {
       trace: { id: 'REQUEST_ID' },
       user: { name: 'jdoe', roles: ['admin'] },
     });
+    audit.stop();
   });
 
   it('does not log to audit logger if event matches ignore filter', async () => {
-    const audit = new AuditService(logger).setup({
+    const audit = new AuditService(logger);
+    const auditSetup = audit.setup({
       license,
       config: {
         enabled: true,
@@ -129,17 +202,20 @@ describe('#asScoped', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
     const request = httpServerMock.createKibanaRequest({
       kibanaRequestState: { requestId: 'REQUEST_ID', requestUuid: 'REQUEST_UUID' },
     });
 
-    await audit.asScoped(request).log({ message: 'MESSAGE', event: { action: 'ACTION' } });
+    await auditSetup.asScoped(request).log({ message: 'MESSAGE', event: { action: 'ACTION' } });
     expect(logger.info).not.toHaveBeenCalled();
+    audit.stop();
   });
 
   it('does not log to audit logger if no event was generated', async () => {
-    const audit = new AuditService(logger).setup({
+    const audit = new AuditService(logger);
+    const auditSetup = audit.setup({
       license,
       config: {
         enabled: true,
@@ -150,13 +226,15 @@ describe('#asScoped', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
     const request = httpServerMock.createKibanaRequest({
       kibanaRequestState: { requestId: 'REQUEST_ID', requestUuid: 'REQUEST_UUID' },
     });
 
-    await audit.asScoped(request).log(undefined);
+    await auditSetup.asScoped(request).log(undefined);
     expect(logger.info).not.toHaveBeenCalled();
+    audit.stop();
   });
 });
 
@@ -376,6 +454,7 @@ describe('#getLogger', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
 
     const auditLogger = auditService.getLogger(pluginId);
@@ -407,6 +486,7 @@ describe('#getLogger', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
 
     const auditLogger = auditService.getLogger(pluginId);
@@ -446,6 +526,7 @@ describe('#getLogger', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
 
     const auditLogger = auditService.getLogger(pluginId);
@@ -475,6 +556,7 @@ describe('#getLogger', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
 
     const auditLogger = auditService.getLogger(pluginId);
@@ -505,6 +587,7 @@ describe('#getLogger', () => {
       getCurrentUser,
       getSpaceId,
       getSID,
+      recordAuditLoggingUsage,
     });
 
     const auditLogger = auditService.getLogger(pluginId);

diff --git a/x-pack/plugins/security/server/audit/audit_service.ts b/x-pack/plugins/security/server/audit/audit_service.ts
@@ -20,6 +20,7 @@ import { AuditEvent, httpRequestEvent } from './audit_events';
 import { SecurityPluginSetup } from '..';
 
 export const ECS_VERSION = '1.6.0';
+export const RECORD_USAGE_INTERVAL = 60 * 60 * 1000; // 1 hour
 
 /**
  * @deprecated
@@ -58,6 +59,7 @@ interface AuditServiceSetupParams {
   getSpaceId(
     request: KibanaRequest
   ): ReturnType<SpacesPluginSetup['spacesService']['getSpaceId']> | undefined;
+  recordAuditLoggingUsage(): void;
 }
 
 export class AuditService {
@@ -69,8 +71,8 @@ export class AuditService {
    * @deprecated
    */
   private allowLegacyAuditLogging = false;
-
   private ecsLogger: Logger;
+  private usageIntervalId?: NodeJS.Timeout;
 
   constructor(private readonly logger: Logger) {
     this.ecsLogger = logger.get('ecs');
@@ -84,6 +86,7 @@ export class AuditService {
     getCurrentUser,
     getSID,
     getSpaceId,
+    recordAuditLoggingUsage,
   }: AuditServiceSetupParams): AuditServiceSetup {
     if (config.enabled && !config.appender) {
       this.licenseFeaturesSubscription = license.features$.subscribe(
@@ -101,6 +104,20 @@ export class AuditService {
       )
     );
 
+    // Record feature usage at a regular interval if enabled and license allows
+    if (config.enabled && config.appender) {
+      license.features$.subscribe((features) => {
+        clearInterval(this.usageIntervalId!);
+        if (features.allowAuditLogging) {
+          recordAuditLoggingUsage();
+          this.usageIntervalId = setInterval(recordAuditLoggingUsage, RECORD_USAGE_INTERVAL);
+          if (this.usageIntervalId.unref) {
+            this.usageIntervalId.unref();
+          }
+        }
+      });
+    }
+
     /**
      * Creates an {@link AuditLogger} scoped to the current request.
      *
@@ -198,6 +215,7 @@ export class AuditService {
       this.licenseFeaturesSubscription.unsubscribe();
       this.licenseFeaturesSubscription = undefined;
     }
+    clearInterval(this.usageIntervalId!);
   }
 }
 

diff --git a/x-pack/plugins/security/server/feature_usage/feature_usage_service.test.ts b/x-pack/plugins/security/server/feature_usage/feature_usage_service.test.ts
@@ -11,11 +11,12 @@ describe('#setup', () => {
     const featureUsage = { register: jest.fn() };
     const securityFeatureUsage = new SecurityFeatureUsageService();
     securityFeatureUsage.setup({ featureUsage });
-    expect(featureUsage.register).toHaveBeenCalledTimes(2);
+    expect(featureUsage.register).toHaveBeenCalledTimes(3);
     expect(featureUsage.register.mock.calls.map((c) => c[0])).toMatchInlineSnapshot(`
       Array [
         "Subfeature privileges",
         "Pre-access agreement",
+        "Audit logging",
       ]
     `);
   });
@@ -39,4 +40,13 @@ describe('start contract', () => {
     expect(featureUsage.notifyUsage).toHaveBeenCalledTimes(1);
     expect(featureUsage.notifyUsage).toHaveBeenCalledWith('Pre-access agreement');
   });
+
+  it('notifies when audit logging is used', () => {
+    const featureUsage = { notifyUsage: jest.fn(), getLastUsages: jest.fn() };
+    const securityFeatureUsage = new SecurityFeatureUsageService();
+    const startContract = securityFeatureUsage.start({ featureUsage });
+    startContract.recordAuditLoggingUsage();
+    expect(featureUsage.notifyUsage).toHaveBeenCalledTimes(1);
+    expect(featureUsage.notifyUsage).toHaveBeenCalledWith('Audit logging');
+  });
 });
diff --git a/x-pack/plugins/security/server/feature_usage/feature_usage_service.ts b/x-pack/plugins/security/server/feature_usage/feature_usage_service.ts
@@ -17,12 +17,14 @@ interface StartDeps {
 export interface SecurityFeatureUsageServiceStart {
   recordPreAccessAgreementUsage: () => void;
   recordSubFeaturePrivilegeUsage: () => void;
+  recordAuditLoggingUsage: () => void;
 }
 
 export class SecurityFeatureUsageService {
   public setup({ featureUsage }: SetupDeps) {
     featureUsage.register('Subfeature privileges', 'gold');
     featureUsage.register('Pre-access agreement', 'gold');
+    featureUsage.register('Audit logging', 'gold');
   }
 
   public start({ featureUsage }: StartDeps): SecurityFeatureUsageServiceStart {
@@ -33,6 +35,9 @@ export class SecurityFeatureUsageService {
       recordSubFeaturePrivilegeUsage() {
         featureUsage.notifyUsage('Subfeature privileges');
       },
+      recordAuditLoggingUsage() {
+        featureUsage.notifyUsage('Audit logging');
+      },
     };
   }
 }