Add session cleanup audit logging (elastic#122419)

* Add session cleanup audit logging * Update snapshots * Added suggestions from code review * Clean up sessions in batches * Added suggestions form code review
kibanamachine · Jan 12, 2022 · 39cef8b · 39cef8b
1 parent a39bca4
commit 39cef8b
Show file tree

Hide file tree

Showing 13 changed files with 806 additions and 359 deletions.
diff --git a/docs/user/security/audit-logging.asciidoc b/docs/user/security/audit-logging.asciidoc
@@ -53,8 +53,11 @@ Refer to the corresponding {es} logs for potential write errors.
 | `user_logout`
 | `unknown` | User is logging out.
 
+| `session_cleanup`
+| `unknown` | Removing invalid or expired session.
+
 | `access_agreement_acknowledged`
-| N/A | User has acknowledged the access agreement.
+| n/a | User has acknowledged the access agreement.
 
 3+a|
 ===== Category: database

diff --git a/x-pack/plugins/security/server/audit/audit_events.test.ts b/x-pack/plugins/security/server/audit/audit_events.test.ts
@@ -15,6 +15,7 @@ import {
   httpRequestEvent,
   SavedObjectAction,
   savedObjectEvent,
+  sessionCleanupEvent,
   SpaceAuditAction,
   spaceAuditEvent,
   userLoginEvent,
@@ -352,6 +353,37 @@ describe('#userLogoutEvent', () => {
   });
 });
 
+describe('#sessionCleanupEvent', () => {
+  test('creates event with `unknown` outcome', () => {
+    expect(
+      sessionCleanupEvent({
+        usernameHash: 'abcdef',
+        sessionId: 'sid',
+        provider: { name: 'basic1', type: 'basic' },
+      })
+    ).toMatchInlineSnapshot(`
+      Object {
+        "event": Object {
+          "action": "session_cleanup",
+          "category": Array [
+            "authentication",
+          ],
+          "outcome": "unknown",
+        },
+        "kibana": Object {
+          "authentication_provider": "basic1",
+          "authentication_type": "basic",
+          "session_id": "sid",
+        },
+        "message": "Removing invalid or expired session for user [hash=abcdef]",
+        "user": Object {
+          "hash": "abcdef",
+        },
+      }
+    `);
+  });
+});
+
 describe('#httpRequestEvent', () => {
   test('creates event with `unknown` outcome', () => {
     expect(

diff --git a/x-pack/plugins/security/server/audit/audit_events.ts b/x-pack/plugins/security/server/audit/audit_events.ts
@@ -156,6 +156,35 @@ export function userLogoutEvent({ username, provider }: UserLogoutParams): Audit
   };
 }
 
+export interface SessionCleanupParams {
+  sessionId: string;
+  usernameHash?: string;
+  provider: AuthenticationProvider;
+}
+
+export function sessionCleanupEvent({
+  usernameHash,
+  sessionId,
+  provider,
+}: SessionCleanupParams): AuditEvent {
+  return {
+    message: `Removing invalid or expired session for user [hash=${usernameHash}]`,
+    event: {
+      action: 'session_cleanup',
+      category: ['authentication'],
+      outcome: 'unknown',
+    },
+    user: {
+      hash: usernameHash,
+    },
+    kibana: {
+      session_id: sessionId,
+      authentication_provider: provider.name,
+      authentication_type: provider.type,
+    },
+  };
+}
+
 export interface AccessAgreementAcknowledgedParams {
   username: string;
   provider: AuthenticationProvider;

diff --git a/x-pack/plugins/security/server/audit/audit_service.test.ts b/x-pack/plugins/security/server/audit/audit_service.test.ts
@@ -67,6 +67,9 @@ describe('#setup', () => {
     ).toMatchInlineSnapshot(`
       Object {
         "asScoped": [Function],
+        "withoutRequest": Object {
+          "log": [Function],
+        },
       }
     `);
     audit.stop();
@@ -254,6 +257,82 @@ describe('#asScoped', () => {
   });
 });
 
+describe('#withoutRequest', () => {
+  it('logs event without additional meta data', async () => {
+    const audit = new AuditService(logger);
+    const auditSetup = audit.setup({
+      license,
+      config,
+      logging,
+      http,
+      getCurrentUser,
+      getSpaceId,
+      getSID,
+      recordAuditLoggingUsage,
+    });
+
+    await auditSetup.withoutRequest.log({ message: 'MESSAGE', event: { action: 'ACTION' } });
+    expect(logger.info).toHaveBeenCalledWith('MESSAGE', {
+      event: { action: 'ACTION' },
+    });
+    audit.stop();
+  });
+
+  it('does not log to audit logger if event matches ignore filter', async () => {
+    const audit = new AuditService(logger);
+    const auditSetup = audit.setup({
+      license,
+      config: {
+        enabled: true,
+        appender: {
+          type: 'console',
+          layout: {
+            type: 'json',
+          },
+        },
+        ignore_filters: [{ actions: ['ACTION'] }],
+      },
+      logging,
+      http,
+      getCurrentUser,
+      getSpaceId,
+      getSID,
+      recordAuditLoggingUsage,
+    });
+
+    await auditSetup.withoutRequest.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);
+    const auditSetup = audit.setup({
+      license,
+      config: {
+        enabled: true,
+        appender: {
+          type: 'console',
+          layout: {
+            type: 'json',
+          },
+        },
+        ignore_filters: [{ actions: ['ACTION'] }],
+      },
+      logging,
+      http,
+      getCurrentUser,
+      getSpaceId,
+      getSID,
+      recordAuditLoggingUsage,
+    });
+
+    await auditSetup.withoutRequest.log(undefined);
+    expect(logger.info).not.toHaveBeenCalled();
+    audit.stop();
+  });
+});
+
 describe('#createLoggingConfig', () => {
   test('sets log level to `info` when audit logging is enabled and appender is defined', async () => {
     const features$ = of({

diff --git a/x-pack/plugins/security/server/audit/audit_service.ts b/x-pack/plugins/security/server/audit/audit_service.ts
@@ -26,11 +26,58 @@ export const ECS_VERSION = '1.6.0';
 export const RECORD_USAGE_INTERVAL = 60 * 60 * 1000; // 1 hour
 
 export interface AuditLogger {
+  /**
+   * Logs an {@link AuditEvent} and automatically adds meta data about the
+   * current user, space and correlation id.
+   *
+   * Guidelines around what events should be logged and how they should be
+   * structured can be found in: `/x-pack/plugins/security/README.md`
+   *
+   * @example
+   * ```typescript
+   * const auditLogger = securitySetup.audit.asScoped(request);
+   * auditLogger.log({
+   *   message: 'User is updating dashboard [id=123]',
+   *   event: {
+   *     action: 'saved_object_update',
+   *     outcome: 'unknown'
+   *   },
+   *   kibana: {
+   *     saved_object: { type: 'dashboard', id: '123' }
+   *   },
+   * });
+   * ```
+   */
   log: (event: AuditEvent | undefined) => void;
 }
 
 export interface AuditServiceSetup {
+  /**
+   * Creates an {@link AuditLogger} scoped to the current request.
+   *
+   * This audit logger logs events with all required user and session info and should be used for
+   * all user-initiated actions.
+   *
+   * @example
+   * ```typescript
+   * const auditLogger = securitySetup.audit.asScoped(request);
+   * auditLogger.log(event);
+   * ```
+   */
   asScoped: (request: KibanaRequest) => AuditLogger;
+
+  /**
+   * {@link AuditLogger} for background tasks only.
+   *
+   * This audit logger logs events without any user or session info and should never be used to log
+   * user-initiated actions.
+   *
+   * @example
+   * ```typescript
+   * securitySetup.audit.withoutRequest.log(event);
+   * ```
+   */
+  withoutRequest: AuditLogger;
 }
 
 interface AuditServiceSetupParams {
@@ -88,46 +135,25 @@ export class AuditService {
       });
     }
 
-    /**
-     * Creates an {@link AuditLogger} scoped to the current request.
-     *
-     * @example
-     * ```typescript
-     * const auditLogger = securitySetup.audit.asScoped(request);
-     * auditLogger.log(event);
-     * ```
-     */
-    const asScoped = (request: KibanaRequest): AuditLogger => {
-      /**
-       * Logs an {@link AuditEvent} and automatically adds meta data about the
-       * current user, space and correlation id.
-       *
-       * Guidelines around what events should be logged and how they should be
-       * structured can be found in: `/x-pack/plugins/security/README.md`
-       *
-       * @example
-       * ```typescript
-       * const auditLogger = securitySetup.audit.asScoped(request);
-       * auditLogger.log({
-       *   message: 'User is updating dashboard [id=123]',
-       *   event: {
-       *     action: 'saved_object_update',
-       *     outcome: 'unknown'
-       *   },
-       *   kibana: {
-       *     saved_object: { type: 'dashboard', id: '123' }
-       *   },
-       * });
-       * ```
-       */
-      const log: AuditLogger['log'] = async (event) => {
+    const log = (event: AuditEvent | undefined) => {
+      if (!event) {
+        return;
+      }
+      if (filterEvent(event, config.ignore_filters)) {
+        const { message, ...eventMeta } = event;
+        this.logger.info(message, eventMeta);
+      }
+    };
+
+    const asScoped = (request: KibanaRequest): AuditLogger => ({
+      log: async (event) => {
         if (!event) {
           return;
         }
         const spaceId = getSpaceId(request);
         const user = getCurrentUser(request);
         const sessionId = await getSID(request);
-        const meta: AuditEvent = {
+        log({
           ...event,
           user:
             (user && {
@@ -141,14 +167,9 @@ export class AuditService {
             ...event.kibana,
           },
           trace: { id: request.id },
-        };
-        if (filterEvent(meta, config.ignore_filters)) {
-          const { message, ...eventMeta } = meta;
-          this.logger.info(message, eventMeta);
-        }
-      };
-      return { log };
-    };
+        });
+      },
+    });
 
     http.registerOnPostAuth((request, response, t) => {
       if (request.auth.isAuthenticated) {
@@ -157,7 +178,10 @@ export class AuditService {
       return t.next();
     });
 
-    return { asScoped };
+    return {
+      asScoped,
+      withoutRequest: { log },
+    };
   }
 
   stop() {

diff --git a/x-pack/plugins/security/server/audit/index.mock.ts b/x-pack/plugins/security/server/audit/index.mock.ts
@@ -14,6 +14,9 @@ export const auditServiceMock = {
       asScoped: jest.fn().mockReturnValue({
         log: jest.fn(),
       }),
+      withoutRequest: {
+        log: jest.fn(),
+      },
     } as jest.Mocked<ReturnType<AuditService['setup']>>;
   },
 };
diff --git a/x-pack/plugins/security/server/audit/index.ts b/x-pack/plugins/security/server/audit/index.ts
@@ -11,6 +11,7 @@ export type { AuditEvent } from './audit_events';
 export {
   userLoginEvent,
   userLogoutEvent,
+  sessionCleanupEvent,
   accessAgreementAcknowledgedEvent,
   httpRequestEvent,
   savedObjectEvent,

diff --git a/x-pack/plugins/security/server/plugin.test.ts b/x-pack/plugins/security/server/plugin.test.ts
@@ -67,6 +67,9 @@ describe('Security Plugin', () => {
         Object {
           "audit": Object {
             "asScoped": [Function],
+            "withoutRequest": Object {
+              "log": [Function],
+            },
           },
           "authc": Object {
             "getCurrentUser": [Function],

diff --git a/x-pack/plugins/security/server/plugin.ts b/x-pack/plugins/security/server/plugin.ts
@@ -310,9 +310,7 @@ export class SecurityPlugin
     });
 
     return Object.freeze<SecurityPluginSetup>({
-      audit: {
-        asScoped: this.auditSetup.asScoped,
-      },
+      audit: this.auditSetup,
       authc: { getCurrentUser: (request) => this.getAuthentication().getCurrentUser(request) },
       authz: {
         actions: this.authorizationSetup.actions,
@@ -347,6 +345,7 @@ export class SecurityPlugin
     const clusterClient = core.elasticsearch.client;
     const { watchOnlineStatus$ } = this.elasticsearchService.start();
     const { session } = this.sessionManagementService.start({
+      auditLogger: this.auditSetup!.withoutRequest,
       elasticsearchClient: clusterClient.asInternalUser,
       kibanaIndexName: this.getKibanaIndexName(),
       online$: watchOnlineStatus$(),