feat(rbac): add audit log for RBAC backend

packages/backend/package.json

@@ -17,6 +17,7 @@
   },
   "dependencies": {
     "@backstage/backend-defaults": "^0.2.17",
+    "@backstage/backend-plugin-api": "^0.6.17",
     "@backstage/plugin-app-backend": "^0.3.65",
     "@backstage/plugin-auth-backend": "^0.22.4",
     "@backstage/plugin-auth-backend-module-guest-provider": "^0.1.3",
@@ -28,6 +29,12 @@
     "@backstage/plugin-search-backend-module-catalog": "^0.1.23",
     "@backstage/plugin-search-backend-module-techdocs": "^0.1.22",
     "@backstage/plugin-techdocs-backend": "^1.10.4",
+    "@manypkg/get-packages": "^1.1.3",
+    "@backstage/config-loader": "^1.8.0",
+    "winston": "^3.11.0",
+    "@backstage/backend-app-api": "^0.7.2",
+    "@backstage/backend-dynamic-feature-service": "^0.2.9",
+    "@backstage/cli-node": "^0.2.5",
     "@janus-idp/backstage-plugin-rbac-backend": "*",
     "app": "*"
   },

packages/backend/src/index.ts

@@ -1,7 +1,28 @@
 import { createBackend } from '@backstage/backend-defaults';
+import { dynamicPluginsSchemasServiceFactory } from '@backstage/backend-dynamic-feature-service';
+import { PackageRoles } from '@backstage/cli-node';
+
+import * as path from 'path';
+
+import { customLogger } from './logger/customLogger';
 
 const backend = createBackend();
 
+backend.add(
+  dynamicPluginsSchemasServiceFactory({
+    schemaLocator(pluginPackage) {
+      const platform = PackageRoles.getRoleInfo(
+        pluginPackage.manifest.backstage.role,
+      ).platform;
+      return path.join(
+        platform === 'node' ? 'dist' : 'dist-scalprum',
+        'configSchema.json',
+      );
+    },
+  }),
+);
+backend.add(customLogger());
+
 backend.add(import('@backstage/plugin-app-backend/alpha'));
 backend.add(import('@backstage/plugin-proxy-backend/alpha'));
 backend.add(import('@backstage/plugin-scaffolder-backend/alpha'));

packages/backend/src/logger/customLogger.ts

@@ -0,0 +1,94 @@
+import {
+  createConfigSecretEnumerator,
+  WinstonLogger,
+} from '@backstage/backend-app-api';
+import { DynamicPluginsSchemasService } from '@backstage/backend-dynamic-feature-service';
+import {
+  coreServices,
+  createServiceFactory,
+  createServiceRef,
+} from '@backstage/backend-plugin-api';
+import { loadConfigSchema } from '@backstage/config-loader';
+
+import { getPackages } from '@manypkg/get-packages';
+import * as winston from 'winston';
+
+const defaultFormat = winston.format.combine(
+  winston.format.timestamp({
+    format: 'YYYY-MM-DD HH:mm:ss',
+  }),
+  winston.format.errors({ stack: true }),
+  winston.format.splat(),
+);
+
+const auditLogFormat = winston.format((info, opts) => {
+  const { isAuditLog, ...newInfo } = info;
+
+  if (isAuditLog) {
+    // keep `isAuditLog` field
+    return opts.isAuditLog ? info : false;
+  }
+
+  // remove `isAuditLog` field from non audit log events
+  return !opts.isAuditLog ? newInfo : false;
+});
+
+const transports = {
+  log: [
+    new winston.transports.Console({
+      format: winston.format.combine(
+        auditLogFormat({ isAuditLog: false }),
+        defaultFormat,
+        winston.format.json(),
+      ),
+    }),
+  ],
+  auditLog: [
+    new winston.transports.Console({
+      format: winston.format.combine(
+        auditLogFormat({ isAuditLog: true }),
+        defaultFormat,
+        winston.format.json(),
+      ),
+    }),
+  ],
+};
+
+const dynamicPluginsSchemasServiceRef =
+  createServiceRef<DynamicPluginsSchemasService>({
+    id: 'core.dynamicplugins.schemas',
+    scope: 'root',
+  });
+
+export const customLogger = createServiceFactory({
+  service: coreServices.rootLogger,
+  deps: {
+    config: coreServices.rootConfig,
+    schemas: dynamicPluginsSchemasServiceRef,
+  },
+  async factory({ config, schemas }) {
+    const logger = WinstonLogger.create({
+      meta: {
+        service: 'backstage',
+      },
+      level: process.env.LOG_LEVEL ?? 'info',
+      format: winston.format.combine(defaultFormat, winston.format.json()),
+      transports: [...transports.log, ...transports.auditLog],
+    });
+
+    const configSchema = await loadConfigSchema({
+      dependencies: (await getPackages(process.cwd())).packages.map(
+        p => p.packageJson.name,
+      ),
+    });
+
+    const secretEnumerator = await createConfigSecretEnumerator({
+      logger,
+      schema: (await schemas.addDynamicPluginsSchemas(configSchema)).schema,
+    });
+    logger.addRedactions(secretEnumerator(config));
+    config.subscribe?.(() => logger.addRedactions(secretEnumerator(config)));
+
+    return logger;
+  },
+});

packages/backend/src/logger/index.ts

@@ -0,0 +1 @@
+export * from './customLogger';

plugins/rbac-backend/docs/audit-log.md

@@ -0,0 +1,49 @@
+# Audit logging
+
+The RBAC backend plugin supports audit logging with the help of the @janus-idp/backstage-plugin-audit-log-node library. Audit logging helps to track the latest changes and events from the RBAC plugin:
+
+- RBAC role changes;
+- RBAC permissions changes;
+- RBAC conditions changes;
+- Changes causing modification of application configuration;
+- Changes causing modification of the permission policy file;
+- GET requests for RBAC permission information;
+- User authorization results to RBAC resources.
+
+The RBAC backend plugin logging doesn't provide information about the actual state of the permissions. The actual state of RBAC permissions can be found in the RBAC UI. Audit logging provides information about the event name, event message, RBAC permission changes, the actor who made these changes, time, log level, stage, status, some part of the request, response, and so on. You can use this information like a history of the RBAC permission hierarchy.
+
+Notice: RBAC permissions and conditions are bound to RBAC roles. However, the RBAC backend plugin logs information about permissions and conditions with the help of separated log messages. That's because for now, the RBAC plugin has a separated API for RBAC roles, RBAC permissions, and RBAC conditions.
+
+## Audit log actor
+
+The audit log actor can be a real REST API user or the RBAC plugin itself. When the actor is a REST API user, then the RBAC plugin logs the user's IP, browser agent, and hostname. The RBAC plugin can also be the actor of the events. In this case, the actor has a name: "rbac-backend". In this case, the plugin typically applies changes from the configuration or permission policy file. Application configuration and permission policy files usually mount to the application deployment with the help of config maps. Unfortunately, the RBAC plugin cannot track who originally made modifications to these resources. But you can enable Kubernetes API audit log: https://kubernetes.io/docs/tasks/debug/debug-cluster/audit. Then you can match RBAC plugin audit log events to the events from Kubernetes logs by time.
+
+## Audit log format
+
+The RBAC plugin prints information to the backend log in JSON format. The format of these messages is defined in the @janus-idp/backstage-plugin-audit-log-node library. Each audit log line contains the key "isAuditLog".
+
+You can change the log level with the help of the environment variable: LOG_LEVEL.
+
+Example logged RBAC events:
+
+a) RBAC role created with corresponding basic permissions and conditional permission:
+
+```json
+backend:start: {"actor":{"actorId":"user:default/andrienkoaleksandr","hostname":"localhost","ip":"::1","userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/125.0.0.0 Safari/537.36"},"eventName":"CreateRole","isAuditLog":true,"level":"info","message":"Created role:default/test","meta":{"author":"user:default/andrienkoaleksandr","createdAt":"Tue, 04 Jun 2024 13:51:45 GMT","description":"some test role","lastModified":"Tue, 04 Jun 2024 13:51:45 GMT","members":["user:default/logarifm","group:default/team-a"],"modifiedBy":"user:default/andrienkoaleksandr","roleEntityRef":"role:default/test","source":"rest"},"plugin":"permission","request":{"body":{"memberReferences":["user:default/logarifm","group:default/team-a"],"metadata":{"description":"some test role"},"name":"role:default/test"},"method":"POST","params":{},"query":{},"url":"/api/permission/roles"},"response":{"status":201},"service":"backstage","stage":"sendResponse","status":"succeeded","timestamp":"2024-06-04 16:51:45"}
+
+backend:start: {"actor":{"actorId":"user:default/andrienkoaleksandr","hostname":"localhost","ip":"::1","userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/125.0.0.0 Safari/537.36"},"eventName":"CreatePolicy","isAuditLog":true,"level":"info","message":"Created permission policies","meta":{"policies":[["role:default/test","scaffolder-template","read","allow"]],"source":"rest"},"plugin":"permission","request":{"body":[{"effect":"allow","entityReference":"role:default/test","permission":"scaffolder-template","policy":"read"}],"method":"POST","params":{},"query":{},"url":"/api/permission/policies"},"response":{"status":201},"service":"backstage","stage":"sendResponse","status":"succeeded","timestamp":"2024-06-04 16:51:45"}
+
+backend:start: {"actor":{"actorId":"user:default/andrienkoaleksandr","hostname":"localhost","ip":"::1","userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/125.0.0.0 Safari/537.36"},"eventName":"CreateCondition","isAuditLog":true,"level":"info","message":"Created conditional permission policy","meta":{"condition":{"conditions":{"params":{"claims":["group:default/team-a"]},"resourceType":"catalog-entity","rule":"IS_ENTITY_OWNER"},"permissionMapping":[{"action":"read","name":"catalog.entity.read"},{"action":"delete","name":"catalog.entity.delete"},{"action":"update","name":"catalog.entity.refresh"}],"pluginId":"catalog","resourceType":"catalog-entity","result":"CONDITIONAL","roleEntityRef":"role:default/test"}},"plugin":"permission","request":{"body":{"conditions":{"params":{"claims":["group:default/team-a"]},"resourceType":"catalog-entity","rule":"IS_ENTITY_OWNER"},"permissionMapping":["read","delete","update"],"pluginId":"catalog","resourceType":"catalog-entity","result":"CONDITIONAL","roleEntityRef":"role:default/test"},"method":"POST","params":{},"query":{},"url":"/api/permission/roles/conditions"},"response":{"body":{"id":9},"status":201},"service":"backstage","stage":"sendResponse","status":"succeeded","timestamp":"2024-06-04 16:51:45"}
+```
+
+b) Check access user to application resource:
+
+```json
+backend:start: {"actor":{"actorId":"user:default/andrienkoaleksandr"},"eventName":"PermissionEvaluationStarted","isAuditLog":true,"level":"info","message":"Policy check for user:default/andrienkoaleksandr","meta":{"action":"create","permissionName":"policy.entity.create","resourceType":"policy-entity","userEntityRef":"user:default/andrienkoaleksandr"},"plugin":"permission","service":"backstage","stage":"evaluatePermissionAccess","status":"succeeded","timestamp":"2024-06-04 16:51:45"}
+
+backend:start: {"actor":{"actorId":"user:default/andrienkoaleksandr"},"eventName":"PermissionEvaluationCompleted","isAuditLog":true,"level":"info","message":"user:default/andrienkoaleksandr is ALLOW for permission 'policy.entity.create', resource type 'policy-entity' and action 'create'","meta":{"action":"create","decision":{"result":"ALLOW"},"permissionName":"policy.entity.create","resourceType":"policy-entity","userEntityRef":"user:default/andrienkoaleksandr"},"plugin":"permission","service":"backstage","stage":"evaluatePermissionAccess","status":"succeeded","timestamp":"2024-06-04 16:51:45"}
+```
+
+Most audit log lines contain a metadata object. The RBAC plugin includes information about RBAC roles, permissions, conditions, and authorization results in this metadata. Metadata types can be found in the RBAC plugin file audit-log/audit-logger.ts.
+
+Notice: You need to properly configure the logger to see nested JSON objects in the audit log lines.

plugins/rbac-backend/package.json

@@ -38,6 +38,7 @@
     "@dagrejs/graphlib": "^2.1.13",
     "@janus-idp/backstage-plugin-rbac-common": "1.4.2",
     "@janus-idp/backstage-plugin-rbac-node": "1.1.1",
+    "@janus-idp/backstage-plugin-audit-log-node": "1.0.2",
     "casbin": "^5.27.1",
     "chokidar": "^3.6.0",
     "csv-parse": "^5.5.5",

plugins/rbac-backend/src/audit-log/audit-logger.ts

@@ -0,0 +1,153 @@
+import {
+  AuthorizeResult,
+  PolicyDecision,
+  ResourcePermission,
+} from '@backstage/plugin-permission-common';
+import { PolicyQuery } from '@backstage/plugin-permission-node';
+
+import { AuditLogOptions } from '@janus-idp/backstage-plugin-audit-log-node';
+import {
+  PermissionAction,
+  PermissionInfo,
+  RoleConditionalPolicyDecision,
+  Source,
+  toPermissionAction,
+} from '@janus-idp/backstage-plugin-rbac-common';
+
+export const RoleEvents = {
+  CREATE_ROLE: 'CreateRole',
+  UPDATE_ROLE: 'UpdateRole',
+  DELETE_ROLE: 'DeleteRole',
+  CREATE_OR_UPDATE_ROLE: 'CreateOrUpdateRole',
+  GET_ROLE: 'GetRole',
+
+  CREATE_ROLE_ERROR: 'CreateRoleError',
+  UPDATE_ROLE_ERROR: 'UpdateRoleError',
+  DELETE_ROLE_ERROR: 'DeleteRoleError',
+  GET_ROLE_ERROR: 'GetRoleError',
+} as const;
+
+export const PermissionEvents = {
+  CREATE_POLICY: 'CreatePolicy',
+  CREATE_OR_UPDATE_POLICY: 'CreateOrUpdatePolicy',
+  UPDATE_POLICY: 'UpdatePolicy',
+  DELETE_POLICY: 'DeletePolicy',
+  GET_POLICY: 'GetPolicy',
+
+  CREATE_POLICY_ERROR: 'CreatePolicyError',
+  UPDATE_POLICY_ERROR: 'UpdatePolicyError',
+  DELETE_POLICY_ERROR: 'DeletePolicyError',
+  GET_POLICY_ERROR: 'GetPolicyError',
+} as const;
+
+export type RoleAuditInfo = {
+  roleEntityRef: string;
+  description?: string;
+  source: Source;
+
+  members: string[];
+};
+
+export type PermissionAuditInfo = {
+  policies: string[][];
+  source: Source;
+};
+
+export const EvaluationEvents = {
+  PERMISSION_EVALUATION_STARTED: 'PermissionEvaluationStarted',
+  PERMISSION_EVALUATION_COMPLETED: 'PermissionEvaluationCompleted',
+  CONDITION_EVALUATION_COMPLETED: 'ConditionEvaluationCompleted',
+  PERMISSION_EVALUATION_FAILED: 'PermissionEvaluationFailed',
+} as const;
+
+export const ListPluginPoliciesEvents = {
+  GET_PLUGINS_POLICIES: 'GetPluginsPolicies',
+  GET_PLUGINS_POLICIES_ERROR: 'GetPluginsPoliciesError',
+};
+
+export const ListConditionEvents = {
+  GET_CONDITION_RULES: 'GetConditionRules',
+  GET_CONDITION_RULES_ERROR: 'GetConditionRulesError',
+};
+
+export type EvaluationAuditInfo = {
+  userEntityRef: string;
+  permissionName: string;
+  action: PermissionAction;
+  resourceType?: string;
+  decision?: PolicyDecision;
+};
+
+export const ConditionEvents = {
+  CREATE_CONDITION: 'CreateCondition',
+  UPDATE_CONDITION: 'UpdateCondition',
+  DELETE_CONDITION: 'DeleteCondition',
+  GET_CONDITION: 'GetCondition',
+
+  CREATE_CONDITION_ERROR: 'CreateConditionError',
+  UPDATE_CONDITION_ERROR: 'UpdateConditionError',
+  DELETE_CONDITION_ERROR: 'DeleteConditionError',
+  GET_CONDITION_ERROR: 'GetConditionError',
+};
+
+export type ConditionAuditInfo = {
+  condition: RoleConditionalPolicyDecision<PermissionInfo>;
+};
+
+export const RBAC_BACKEND = 'rbac-backend';
+
+// Audit log stage for processing Role-Based Access Control (RBAC) data
+export const HANDLE_RBAC_DATA_STAGE = 'handleRBACData';
+
+// Audit log stage for determining access rights based on user permissions and resource information
+export const EVALUATE_PERMISSION_ACCESS_STAGE = 'evaluatePermissionAccess';
+
+// Audit log stage for sending the response to the client about handled permission policies, roles, and condition policies
+export const SEND_RESPONSE_STAGE = 'sendResponse';
+export const RESPONSE_ERROR = 'responseError';
+
+export function createPermissionEvaluationOptions(
+  message: string,
+  userEntityRef: string,
+  request: PolicyQuery,
+  policyDecision?: PolicyDecision,
+): AuditLogOptions {
+  const auditInfo: EvaluationAuditInfo = {
+    userEntityRef,
+    permissionName: request.permission.name,
+    action: toPermissionAction(request.permission.attributes),
+  };
+
+  const resourceType = (request.permission as ResourcePermission).resourceType;
+  if (resourceType) {
+    auditInfo.resourceType = resourceType;
+  }
+
+  let eventName;
+  if (!policyDecision) {
+    eventName = EvaluationEvents.PERMISSION_EVALUATION_STARTED;
+  } else {
+    auditInfo.decision = policyDecision;
+
+    switch (policyDecision.result) {
+      case AuthorizeResult.DENY:
+      case AuthorizeResult.ALLOW:
+        eventName = EvaluationEvents.PERMISSION_EVALUATION_COMPLETED;
+        break;
+      case AuthorizeResult.CONDITIONAL:
+        eventName = EvaluationEvents.CONDITION_EVALUATION_COMPLETED;
+        break;
+      default:
+        throw new Error('Unknown policy decision result');
+    }
+  }
+
+  return {
+    actorId: userEntityRef,
+    message,
+    eventName,
+    metadata: auditInfo,
+    stage: EVALUATE_PERMISSION_ACCESS_STAGE,
+    status: 'succeeded',
+  };
+}