diff --git a/app/interactors/application_interactor.rb b/app/interactors/application_interactor.rb index 1f6d08b..9b66d59 100644 --- a/app/interactors/application_interactor.rb +++ b/app/interactors/application_interactor.rb @@ -2,9 +2,10 @@ class ApplicationInteractor include Interactor def audit_log + return if context.identity.nil? result = context.success? ? "success" : "failure" - level = context.success? ? :info : :error payload = { + request_id: Thread.current[:request_id], action: "#{self.class.name}", result: result, error: context.error&.message, @@ -12,6 +13,6 @@ def audit_log cert_common_name: context.request&.try(:common_name), kv_path: context.request&.try(:kv_path) }.compact! - AuditLogger.new.send(level, payload) + AuditLog.create!(payload) end end diff --git a/app/lib/audit_logger.rb b/app/lib/audit_logger.rb deleted file mode 100644 index 788a6cc..0000000 --- a/app/lib/audit_logger.rb +++ /dev/null @@ -1,6 +0,0 @@ -class AuditLogger < ActiveSupport::Logger - def initialize - super(Config[:audit_log_file]) - self.formatter = JsonLogFormatter.new - end -end diff --git a/app/lib/json_log_formatter.rb b/app/lib/json_log_formatter.rb deleted file mode 100644 index 5e759cd..0000000 --- a/app/lib/json_log_formatter.rb +++ /dev/null @@ -1,17 +0,0 @@ -class JsonLogFormatter < ActiveSupport::Logger::SimpleFormatter - def call(severity, timestamp, _progname, message) - # request_id is unique to the life of the api request - request_id = Thread.current[:request_id] - json = { - type: severity, - time: "#{timestamp}", - request_id: request_id - } - if message.is_a? Hash - json = json.merge(message) - else - json[:message] = message - end - "#{json.to_json}\n" - end -end diff --git a/app/models/audit_log.rb b/app/models/audit_log.rb new file mode 100644 index 0000000..05e659a --- /dev/null +++ b/app/models/audit_log.rb @@ -0,0 +1,7 @@ +class AuditLog < ApplicationRecord + validates :request_id, :action, :result, :subject, presence: true + + if Config[:db_encryption] + encrypts :request_id, :action, :result, :error, :subject, :cert_common_name, :kv_path + end +end diff --git a/config/astral.yml b/config/astral.yml index 733b9b9..2e7ae33 100644 --- a/config/astral.yml +++ b/config/astral.yml @@ -31,9 +31,6 @@ shared: app_registry_client_cert: app_registry_client_key: - # User activity logging - audit_log_file: <%= "#{Rails.root.join('log')}/astral-audit.log" %> - oidc_client_id: oidc_client_secret: oidc_redirect_uris: http://localhost:8250/oidc/callback diff --git a/db/migrate/20241120172746_create_audit_logs.rb b/db/migrate/20241120172746_create_audit_logs.rb new file mode 100644 index 0000000..dd9a286 --- /dev/null +++ b/db/migrate/20241120172746_create_audit_logs.rb @@ -0,0 +1,15 @@ +class CreateAuditLogs < ActiveRecord::Migration[7.2] + def change + create_table :audit_logs do |t| + t.string :request_id, null: false + t.string :action, null: false + t.string :result, null: false + t.string :error, null: true + t.string :subject, null: false + t.string :cert_common_name, null: true + t.string :kv_path, null: true + t.timestamps + end + add_index :audit_logs, [ :subject, :created_at ] + end +end diff --git a/db/schema.rb b/db/schema.rb index 891ccca..e5dc129 100644 --- a/db/schema.rb +++ b/db/schema.rb @@ -10,7 +10,7 @@ # # It's strongly recommended that you check this file into your version control system. -ActiveRecord::Schema[7.2].define(version: 2024_11_14_150941) do +ActiveRecord::Schema[7.2].define(version: 2024_11_20_172746) do create_table "domains", force: :cascade do |t| t.string "fqdn", null: false t.text "users" @@ -30,4 +30,17 @@ t.datetime "updated_at", null: false t.index ["path"], name: "index_kv_metadata_on_path", unique: true end + + create_table "audit_logs", force: :cascade do |t| + t.string "request_id", null: false + t.string "action", null: false + t.string "result", null: false + t.string "error" + t.string "subject", null: false + t.string "cert_common_name" + t.string "kv_path" + t.datetime "created_at", null: false + t.datetime "updated_at", null: false + t.index ["subject", "created_at"], name: "index_audit_logs_on_subject_and_created_at" + end end diff --git a/test/interactors/application_interactor_test.rb b/test/interactors/application_interactor_test.rb index b189059..3639406 100644 --- a/test/interactors/application_interactor_test.rb +++ b/test/interactors/application_interactor_test.rb @@ -5,13 +5,7 @@ def setup @domain = domains(:owner_match) @identity = Identity.new(subject: @domain.users.first) @cr = Requests::CertIssueRequest.new(common_name: @domain.fqdn) - @log = Tempfile.new("log-test") - Config[:audit_log_file] = @log.path - end - - def teardown - @log.close - @log.unlink + Thread.current[:request_id] = "request_id" end test ".call will be logged as success" do @@ -23,7 +17,9 @@ def call end) rslt = SuccessAction.call(identity: @identity, request: @cr) assert rslt.success? - assert_match %Q("action":"SuccessAction","result":"success","subject":"john.doe@example.com","cert_common_name":"example.com"), @log.readlines.last + log = AuditLog.last + expected = { "action"=>"SuccessAction", "result"=>"success", "subject"=>"john.doe@example.com", "cert_common_name"=>"example.com" } + assert expected <= log.attributes end test ".call will be logged as failure" do @@ -36,6 +32,8 @@ def call end) rslt = FailAction.call(identity: @identity, request: @cr) assert_not rslt.success? - assert_match %Q("action":"FailAction","result":"failure","subject":"john.doe@example.com","cert_common_name":"example.com"), @log.readlines.last + log = AuditLog.last + expected = { "action"=>"FailAction", "result"=>"failure", "subject"=>"john.doe@example.com", "cert_common_name"=>"example.com" } + assert expected <= log.attributes end end diff --git a/test/interactors/authenticate_identity_test.rb b/test/interactors/authenticate_identity_test.rb index 5a2861c..39a6149 100644 --- a/test/interactors/authenticate_identity_test.rb +++ b/test/interactors/authenticate_identity_test.rb @@ -4,6 +4,7 @@ class AuthenticateIdentityTest < ActiveSupport::TestCase def setup @interactor = AuthenticateIdentity @identity = Identity.new(subject: "test@example.com", groups: [ "admin_group" ]) + Thread.current[:request_id] = "request_id" end test ".call success" do diff --git a/test/interactors/authorize_cert_request_test.rb b/test/interactors/authorize_cert_request_test.rb index b54aa28..119b28c 100644 --- a/test/interactors/authorize_cert_request_test.rb +++ b/test/interactors/authorize_cert_request_test.rb @@ -6,6 +6,7 @@ def setup @identity = Identity.new(subject: @domain.users.first) @cr = Requests::CertIssueRequest.new(common_name: @domain.fqdn) @interactor = AuthorizeCertRequest + Thread.current[:request_id] = "request_id" end test ".call with matching owner" do diff --git a/test/interactors/obtain_cert_test.rb b/test/interactors/obtain_cert_test.rb index 32086aa..2246b4a 100644 --- a/test/interactors/obtain_cert_test.rb +++ b/test/interactors/obtain_cert_test.rb @@ -4,11 +4,13 @@ class ObtainCertTest < ActiveSupport::TestCase def setup @interactor = ObtainCert @cert = OpenStruct.new(certificate: "certificate", ca_chain: "ca_chain") + Thread.current[:request_id] = "request_id" end test ".call success" do request = Requests::CertIssueRequest.new identity = Identity.new + identity.sub = SecureRandom.hex(4) mock = Minitest::Mock.new mock.expect :call, @cert, [ identity, request ] Services::Certificate.stub :issue_cert, mock do @@ -21,6 +23,7 @@ def setup test ".call failure" do request = Requests::CertIssueRequest.new identity = Identity.new + identity.sub = SecureRandom.hex(4) mock = Minitest::Mock.new mock.expect :call, nil, [ identity, request ] Services::Certificate.stub :issue_cert, mock do diff --git a/test/lib/json_log_formatter_test.rb b/test/lib/json_log_formatter_test.rb deleted file mode 100644 index ad73b6e..0000000 --- a/test/lib/json_log_formatter_test.rb +++ /dev/null @@ -1,28 +0,0 @@ -require "test_helper" - -class JsonLogFormatterTest < ActiveSupport::TestCase - setup do - Thread.current[:request_id] = nil - end - - test "#call formats logformatter inputs as json" do - t = Time.now - result = JsonLogFormatter.new.call("info", t, nil, "some message") - assert_equal %Q({"type":"info","time":"#{t}","request_id":null,"message":"some message"}\n), result - end - - test "#call accepts and merges a Hash type for the message" do - t = Time.now - result = JsonLogFormatter.new.call("info", t, nil, { key: "some message", key2: "another" }) - assert_equal %Q({"type":"info","time":"#{t}","request_id":null,"key":"some message","key2":"another"}\n), result - end - - test "#call can render a thread local request_id" do - t = Time.now - req_id = SecureRandom.hex - Thread.stub :current, { request_id: req_id } do - result = JsonLogFormatter.new.call("info", t, nil, { key: "some message" }) - assert_equal %Q({"type":"info","time":"#{t}","request_id":"#{req_id}","key":"some message"}\n), result - end - end -end diff --git a/test/models/audit_log_test.rb b/test/models/audit_log_test.rb new file mode 100644 index 0000000..02e56c6 --- /dev/null +++ b/test/models/audit_log_test.rb @@ -0,0 +1,30 @@ +require "test_helper" + +class AuditLogTest < ActiveSupport::TestCase + def setup + @attributes = { + request_id: "uuid1", + action: "string1", + result: "string2", + subject: "string3", + cert_common_name: "string4" + } + @audit_log = AuditLog.new(@attributes) + end + + test "#new should set attributes from attributes argument" do + @attributes.each do |key, value| + assert_equal value, @audit_log.send(key), "Attribute #{key} was not set correctly" + end + end + + test "#valid? should be valid with valid attributes" do + assert @audit_log.valid? + end + + test "#valid? should require an result" do + @audit_log.result = nil + assert_not @audit_log.valid? + assert_includes @audit_log.errors[:result], "can't be blank" + end +end