From 2b5071ff36da10af6b9bd40864700d36d30e51ec Mon Sep 17 00:00:00 2001 From: Thom Heymann <190132+thomheymann@users.noreply.github.com> Date: Wed, 6 Jan 2021 18:47:41 +0000 Subject: [PATCH] Report audit logging feature usage (#87457) * Report audit logging feature usage * Fix mock * Added unref --- .../security/common/licensing/index.mock.ts | 6 +- .../server/audit/audit_service.test.ts | 105 ++++++++++++++++-- .../security/server/audit/audit_service.ts | 20 +++- .../feature_usage_service.test.ts | 12 +- .../feature_usage/feature_usage_service.ts | 5 + .../server/feature_usage/index.mock.ts | 1 + x-pack/plugins/security/server/plugin.ts | 1 + 7 files changed, 134 insertions(+), 16 deletions(-) diff --git a/x-pack/plugins/security/common/licensing/index.mock.ts b/x-pack/plugins/security/common/licensing/index.mock.ts index df7d8cd7b416b..88cb3206a253c 100644 --- 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 => ({ + create: (features?: Partial): jest.Mocked => ({ 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 index 91c656ad69f18..e828f0135d44b 100644 --- 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) => { return ConfigSchema.validate(settings); }; @@ -28,18 +35,20 @@ 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, @@ -47,6 +56,7 @@ describe('#setup', () => { getCurrentUser, getSpaceId, getSID, + recordAuditLoggingUsage, }) ).toMatchInlineSnapshot(` Object { @@ -54,10 +64,12 @@ describe('#setup', () => { "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,12 +85,67 @@ 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, @@ -86,14 +153,17 @@ describe('#setup', () => { 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, @@ -101,12 +171,13 @@ 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).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 index 4ad1f873581c9..7ecdef0ab4e4e 100644 --- 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 | 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 index 46796fa73ef26..e8ad9a77b5d5f 100644 --- 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 index 1bc1e664981bf..98338e172bb12 100644 --- 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'); + }, }; } } diff --git a/x-pack/plugins/security/server/feature_usage/index.mock.ts b/x-pack/plugins/security/server/feature_usage/index.mock.ts index 6ed42145abd76..e934222ab22af 100644 --- a/x-pack/plugins/security/server/feature_usage/index.mock.ts +++ b/x-pack/plugins/security/server/feature_usage/index.mock.ts @@ -11,6 +11,7 @@ export const securityFeatureUsageServiceMock = { return { recordPreAccessAgreementUsage: jest.fn(), recordSubFeaturePrivilegeUsage: jest.fn(), + recordAuditLoggingUsage: jest.fn(), } as jest.Mocked; }, }; diff --git a/x-pack/plugins/security/server/plugin.ts b/x-pack/plugins/security/server/plugin.ts index 070e187e869b1..450de2fc31329 100644 --- a/x-pack/plugins/security/server/plugin.ts +++ b/x-pack/plugins/security/server/plugin.ts @@ -204,6 +204,7 @@ export class Plugin { getSpaceId: (request) => spaces?.spacesService.getSpaceId(request), getSID: (request) => session.getSID(request), getCurrentUser: (request) => authenticationSetup.getCurrentUser(request), + recordAuditLoggingUsage: () => this.featureUsageServiceStart?.recordAuditLoggingUsage(), }); const legacyAuditLogger = new SecurityAuditLogger(audit.getLogger());