From 7fd26e0d15da40d48264793ebadfa681d85989fa Mon Sep 17 00:00:00 2001 From: Joao Victor Portal Date: Mon, 7 Feb 2022 17:00:59 -0300 Subject: [PATCH] Fault Management API request audit logging Here is added a hook to the WSGI compliant Pecan server that receives the Fault Management API requests. This hook logs the needed request data to "/var/log/fm-api.log". All requests are logged except the ones of "GET" type. The code is a port from the same hook that exists in "starlingx/config" repository, also called "AuditLogging". Note: there are no "POST" or "PUT" requests available in Fault Management API v1. Test Plan: PASS: Successfully deploy an AIO-SX and verify that the logs of "fm-api" service are present in file "/var/log/fm-api.log". PASS: In the deployed AIO-SX, execute command "fm alarm-list" and check that no GET requests was logged in "fm-api.log". PASS: In the deployed AIO-SX, execute command "fm alarm-delete 1111" and check that a "DELETE /v1/alarms/1111" request was logged in "fm-api.log" with status "404". PASS: In the deployed AIO-SX, execute command "fm event-suppress --alarm_id " and check that a "PATCH /v1/event_suppression/" request was logged in "fm-api.log" with status "200". PASS: Successfully build all packages of this repository as Debian packages: fm-api, fm-common, fm-doc, fm-mgr, fm-rest-api and python-fmclient. Story: 2009824 Task: 44468 Depends-On: https://review.opendev.org/c/starlingx/config-files/+/828200 Signed-off-by: Joao Victor Portal Change-Id: I25bf662ed9e792b30ae1f90329bd35b918f0a5f7 --- fm-mgr/sources/fm.logrotate | 15 ++++ fm-rest-api/fm/fm/api/config.py | 6 +- fm-rest-api/fm/fm/api/hooks.py | 111 +++++++++++++++++++++++++- fm-rest-api/fm/scripts/fm-api.service | 2 +- 4 files changed, 131 insertions(+), 3 deletions(-) diff --git a/fm-mgr/sources/fm.logrotate b/fm-mgr/sources/fm.logrotate index 99d6714b..17a0c9a9 100644 --- a/fm-mgr/sources/fm.logrotate +++ b/fm-mgr/sources/fm.logrotate @@ -4,6 +4,21 @@ # SPDX-License-Identifier: Apache-2.0 # +/var/log/fm-api.log +{ + create 0640 root root + size 10M + start 1 + rotate 20 + missingok + compress + sharedscripts + postrotate + systemctl reload syslog-ng > /dev/null 2>&1 || true + endscript + delaycompress +} + /var/log/fm-event.log { create 0640 root root diff --git a/fm-rest-api/fm/fm/api/config.py b/fm-rest-api/fm/fm/api/config.py index 781c61b5..de6ccee7 100644 --- a/fm-rest-api/fm/fm/api/config.py +++ b/fm-rest-api/fm/fm/api/config.py @@ -1,5 +1,5 @@ # -# Copyright (c) 2018 Wind River Systems, Inc. +# Copyright (c) 2018, 2022 Wind River Systems, Inc. # # SPDX-License-Identifier: Apache-2.0 # @@ -43,6 +43,7 @@ app = { 'hooks': [ hooks.ContextHook(), hooks.DBHook(), + hooks.AuditLogging(), ], 'acl_public_routes': [ '/', @@ -65,6 +66,9 @@ def init(args, **kwargs): def setup_logging(): """Sets up the logging options for a log with supplied name.""" + extra_log_level_defaults = ['eventlet.wsgi.server=WARN'] + logging.set_defaults(default_log_levels=logging.get_default_log_levels() + + extra_log_level_defaults) logging.setup(cfg.CONF, "fm") LOG.debug("Logging enabled!") LOG.debug("%(prog)s version %(version)s", diff --git a/fm-rest-api/fm/fm/api/hooks.py b/fm-rest-api/fm/fm/api/hooks.py index aabb2b11..10c3488a 100644 --- a/fm-rest-api/fm/fm/api/hooks.py +++ b/fm-rest-api/fm/fm/api/hooks.py @@ -1,14 +1,18 @@ # -# Copyright (c) 2018 Wind River Systems, Inc. +# Copyright (c) 2018, 2022 Wind River Systems, Inc. # # SPDX-License-Identifier: Apache-2.0 # +import re +import time +from six.moves.urllib.parse import urlparse import webob from pecan import hooks from oslo_config import cfg from oslo_log import log from oslo_serialization import jsonutils +from oslo_utils import uuidutils from fm.common import context from fm.db import api as dbapi @@ -18,6 +22,13 @@ CONF = cfg.CONF LOG = log.getLogger(__name__) +audit_log_name = "{}.{}".format(__name__, "auditor") +auditLOG = log.getLogger(audit_log_name) + + +def generate_request_id(): + return 'req-%s' % uuidutils.generate_uuid() + class ContextHook(hooks.PecanHook): """Configures a request context and attaches it to the request. @@ -86,3 +97,101 @@ class DBHook(hooks.PecanHook): def before(self, state): state.request.dbapi = dbapi.get_instance() + + +class AuditLogging(hooks.PecanHook): + """ + Performs audit logging of all Fault Manager + ["POST", "PUT", "PATCH", "DELETE"] REST requests. + """ + + def __init__(self): + self.log_methods = ["POST", "PUT", "PATCH", "DELETE"] + + def before(self, state): + state.request.start_time = time.time() + + def __after(self, state): + + method = state.request.method + if method not in self.log_methods: + return + + now = time.time() + try: + elapsed = now - state.request.start_time + except AttributeError: + LOG.info("Start time is not in request, setting it to 0.") + elapsed = 0 + + environ = state.request.environ + server_protocol = environ["SERVER_PROTOCOL"] + + response_content_length = state.response.content_length + + user_id = state.request.headers.get('X-User-Id') + user_name = state.request.headers.get('X-User', user_id) + tenant_id = state.request.headers.get('X-Tenant-Id') + tenant = state.request.headers.get('X-Tenant', tenant_id) + domain_name = state.request.headers.get('X-User-Domain-Name') + try: + request_id = state.request.context.request_id + except AttributeError: + LOG.info("Request id is not in request, setting it to an " + "auto generated id.") + request_id = generate_request_id() + + url_path = urlparse(state.request.path_qs).path + + def json_post_data(rest_state): + if 'form-data' in rest_state.request.headers.get('Content-Type'): + return " POST: {}".format(rest_state.request.params) + if not hasattr(rest_state.request, 'json'): + return "" + return " POST: {}".format(rest_state.request.json) + + # Filter password from log + filtered_json = re.sub(r'{[^{}]*(passwd_hash|community|password)[^{}]*},*', + '', + json_post_data(state)) + + log_data = \ + "{} \"{} {} {}\" status: {} len: {} time: {}{} host:{}" \ + " agent:{} user: {} tenant: {} domain: {}".format( + state.request.remote_addr, + state.request.method, + url_path, + server_protocol, + state.response.status_int, + response_content_length, + elapsed, + filtered_json, + state.request.host, + state.request.user_agent, + user_name, + tenant, + domain_name) + + # The following ctx object will be output in the logger as + # something like this: + # [req-088ed3b6-a2c9-483e-b2ad-f1b2d03e06e6 + # 3d76d3c1376744e8ad9916a6c3be3e5f + # ca53e70c76d847fd860693f8eb301546] + # When the ctx is defined, the formatter (defined in common/log.py) requires that keys + # request_id, user, tenant be defined within the ctx + ctx = {'request_id': request_id, + 'user': user_id, + 'tenant': tenant_id} + + auditLOG.info("{}".format(log_data), context=ctx) + + def after(self, state): + try: + self.__after(state) + except Exception: + # Logging and then swallowing exception to ensure + # rest service does not fail even if audit logging fails + auditLOG.exception("Exception in AuditLogging on event 'after'") + + def on_error(self, state, e): + auditLOG.exception("Exception in AuditLogging passed to event 'on_error': " + str(e)) diff --git a/fm-rest-api/fm/scripts/fm-api.service b/fm-rest-api/fm/scripts/fm-api.service index 0256df77..77e8f8a3 100644 --- a/fm-rest-api/fm/scripts/fm-api.service +++ b/fm-rest-api/fm/scripts/fm-api.service @@ -1,6 +1,6 @@ [Unit] Description=Fault Management REST API Service -After=nfscommon.service sw-patch.service +After=nfscommon.service sw-patch.service syslog-ng.service After=network-online.target systemd-udev-settle.service [Service]