feat(logger): introduce audit logging #217

vkrizan · 2021-02-02T16:42:07Z

Introduction of a middleware and utility to add entries to an audit log. By default it logs them to STDOUT, but eventually it can be tied into CloudWatch. Log entries are formatted into JSON, split by a new-line. Usage is documented in README.

TODO:

Capture Rails requests
Add tests
Find a way to have a shortcut to the logger
Support within a Sidekiq
~~Support within a Racecar~~ (only general logging)

Reference: RHICOMPL-1217

vkrizan · 2021-02-02T16:47:26Z

@akofink, here is the audit logger to get an idea. It is still experimental, and if it would not be fitted in this common package we can bundle it in our Compliance app. Feel free to check it out and comment. Thanks!

dippy-bot · 2021-02-03T12:05:17Z

Checked commits vkrizan/insights-api-common-rails@04d8aa0~...58e6586 with ruby 2.5.7, rubocop 0.82.0, haml-lint 0.35.0, and yamllint
4 files checked, 0 offenses detected
Everything looks fine. ⭐

akofink

Nice work, @vkrizan! Just a few minor comments/questions, but it seems reasonable to me. I'd like to revisit it to actually test it with compliance once it's ready.

akofink · 2021-02-03T15:34:56Z

README.md

+end
+```
+
+### Insights::Api::Common::Filter


Seems like this should still be an H4. Same with Insights::Api::Common::AuditLog above. See #### Sorting Results below.

This one I was not sure about. I'd let owners to look into it. The "Usage" is H2, so the next one should be H3. I'm not sure whether the "Sorting Results" are part of the Filter or not.

Nothing says you have to use headers in order H1 -> H2 -> H3 etc. H1 -> H3 -> H5 works just as well, probably chosen so the markdown renders more nicely in the GitHub UI without overly large headers.

There are document composition guidelines, hence the structure (and order).

akofink · 2021-02-03T15:44:51Z

lib/insights/api/common/audit_log.rb

+        return unless block_given?
+
+        yield
+        Thread.current[:audit_account_number] = original


I guess, another option would be to set this to nil. I'm fine with the current implementation, so long as logs don't show the incorrect account_number from a thread servicing multiple requests.

We use hooks for the auth, which means that the account_number would be only setting. Ensuring that the account num is reset is one thing I'm working on. It would not be a 100%, but at least it should cover controllers.

I suggest setting the original account number in ensure block in case of exception

akofink · 2021-02-03T15:52:08Z

lib/insights/api/common/audit_log/formatter.rb

+      def account_number
+        Thread.current[:audit_account_number]
+      end


This could just be an attr_accessor on the Formatter and set by the AuditLog in with_account.

There is only a one instance of Formatter. Setting it on that instance would not work correctly on multi-threaded env.

There will be one instance of Formatter per thread as written afaik. Thread.current represents only the local thread, so it also won't share information across threads in a multi-threaded env.

Thread.current represents only the local thread, so it also won't share information across threads in a multi-threaded env.

^ That's the sole purpose of this.

I'd like to keep it defensive as is. I don't think that there is a separate instance for each thread as it is instantiated once with a logger. I don't want to rely on that assumption either.

akofink · 2021-02-03T16:03:16Z

lib/insights/api/common/audit_log/middleware.rb

+        @app.call(env).tap do |status, _headers, _body|
+          @status = status
+          response_finished
+        end


akofink · 2021-02-03T16:05:45Z

lib/insights/api/common/audit_log/middleware.rb

+      def generate_message
+        status_label = Rack::Utils::HTTP_STATUS_CODES[status]
+        msg = "#{request.method} #{request.original_fullpath} -> #{status} #{status_label}"
+        if evidence[:unpermitted_parameters]
+          msg += "; unpermitted params #{fmt_params(evidence[:unpermitted_parameters])}"
+        end
+        if evidence[:halted_callback].present?
+          msg += "; filter chain halted by :#{evidence[:halted_callback]}"
+        end
+        msg
+      end


Are the headers logged anywhere? It may be good to include, but it may also present a security risk to include the X_RH_IDENTITY header.

Inspecting X_RH_IDENTITY is a good idea, and can be done here. That's mainly the reason why this is a middleware (to access the request and headers).

The headers may also include X_RH_REQUEST_ID (or something similar), which can be important to tracing uploads, etc. across services.

Awesome! I guess we can incorporate that in the second iteration.

akofink · 2021-02-03T16:08:41Z

lib/insights/api/common/audit_log/middleware.rb

+      def fmt_params(params)
+        params.map { |e| ":#{e}" }.join(", ")
+      end


Does it work with rails parameter filtering for sensitive params? We should verify this/add a test for this case.

https://guides.rubyonrails.org/action_controller_overview.html#log-filtering

This only lists the params, not their value. The code snippet is strait from Rails logger.

Ah! I missed that. Is it possible to log the param values? I think it'd be really useful to be able to debug errors/malfunctions with requests, but we need to ensure they're filtered based on the built in log filtering.

It would be possible, but the notification does not provide them. https://guides.rubyonrails.org/active_support_instrumentation.html#unpermitted-parameters-action-controller

Please keep in mind that this is a audit log with a purpose of retracing steps one has taken. Mostly access/denial/changes to a resource, etc. If details would be necessary an app log can be of help. Hence the transation_ids. 😉

slemrmartin

@vkrizan is the audit log intended only for APIs or also for all other services?

slemrmartin · 2021-02-09T12:44:07Z

lib/insights/api/common/audit_log.rb

+
+      def init_logger(logger = nil)
+        logger ||= Logger.new($stdout)
+        logger.level = Logger::INFO


in topological/sources we are using ENV['LOG_LEVEL'] for ruby and ENV['RAILS_LOG_LEVEL'] for rails.
what about logger.level= ENV[...] || Logger::INFO

The level is hardcoded deliberately, as this is not going to be configurable. The idea is to use info/warn/error for audit logs. The end result might not even use and/or format the level. The difference would be only whether it is a failure/success.

vkrizan · 2021-02-09T14:52:14Z

@slemrmartin It is a global thing, not directly related to APIs. I was operating on the fact that the main module is Insights::API::Common. Do you have any suggestion where to move it? Is there other common package for Insights where we can move it?

vkrizan force-pushed the feat-audit-logging branch from 428bc45 to bc1470f Compare February 2, 2021 16:43

feat(logger): introduce audit logging

04d8aa0

vkrizan force-pushed the feat-audit-logging branch from bc1470f to 04d8aa0 Compare February 2, 2021 16:45

feat(logger): sidekiq evidence for audit log

58e6586

akofink reviewed Feb 3, 2021

View reviewed changes

slemrmartin requested review from lindgrenj6 and hsong-rh February 4, 2021 10:42

vkrizan mentioned this pull request Feb 8, 2021

feat(logging): RHICOMPL-1217 introduce audit logging RedHatInsights/compliance-backend#734

Merged

18 tasks

slemrmartin reviewed Feb 9, 2021

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat(logger): introduce audit logging #217

feat(logger): introduce audit logging #217

vkrizan commented Feb 2, 2021 •

edited

Loading

vkrizan commented Feb 2, 2021

dippy-bot commented Feb 3, 2021

akofink left a comment

akofink Feb 3, 2021

vkrizan Feb 3, 2021

akofink Feb 3, 2021

vkrizan Feb 4, 2021

akofink Feb 3, 2021

vkrizan Feb 3, 2021

slemrmartin Feb 9, 2021

akofink Feb 3, 2021

vkrizan Feb 3, 2021

akofink Feb 3, 2021

vkrizan Feb 4, 2021

akofink Feb 3, 2021

akofink Feb 3, 2021

vkrizan Feb 3, 2021

akofink Feb 3, 2021

vkrizan Feb 3, 2021

akofink Feb 3, 2021

vkrizan Feb 3, 2021

akofink Feb 3, 2021

vkrizan Feb 3, 2021

slemrmartin left a comment

slemrmartin Feb 9, 2021

vkrizan Feb 9, 2021 •

edited

Loading

vkrizan commented Feb 9, 2021

feat(logger): introduce audit logging #217

Are you sure you want to change the base?

feat(logger): introduce audit logging #217

Conversation

vkrizan commented Feb 2, 2021 • edited Loading

vkrizan commented Feb 2, 2021

dippy-bot commented Feb 3, 2021

akofink left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

slemrmartin left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vkrizan Feb 9, 2021 • edited Loading

Choose a reason for hiding this comment

vkrizan commented Feb 9, 2021

vkrizan commented Feb 2, 2021 •

edited

Loading

vkrizan Feb 9, 2021 •

edited

Loading