X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/b01138f2ed3b666fd6075a6d77caddb5d5ca91e1..cadfd226ac8911d34d7dc66ea75ac977ec1319d8:/services/api/test/unit/log_test.rb diff --git a/services/api/test/unit/log_test.rb b/services/api/test/unit/log_test.rb index 22808c5ed6..8a878ada91 100644 --- a/services/api/test/unit/log_test.rb +++ b/services/api/test/unit/log_test.rb @@ -1,4 +1,9 @@ +# Copyright (C) The Arvados Authors. All rights reserved. +# +# SPDX-License-Identifier: AGPL-3.0 + require 'test_helper' +require 'audit_logs' class LogTest < ActiveSupport::TestCase include CurrentApiClient @@ -6,10 +11,10 @@ class LogTest < ActiveSupport::TestCase EVENT_TEST_METHODS = { :create => [:created_at, :assert_nil, :assert_not_nil], :update => [:modified_at, :assert_not_nil, :assert_not_nil], - :destroy => [nil, :assert_not_nil, :assert_nil], + :delete => [nil, :assert_not_nil, :assert_nil], } - def setup + setup do @start_time = Time.now @log_count = 1 end @@ -51,15 +56,20 @@ class LogTest < ActiveSupport::TestCase 'old_etag', 'old_attributes') assert_properties(new_props_test, event_type, props, 'new_etag', 'new_attributes') + ['old_attributes', 'new_attributes'].each do |logattr| + next if !props[logattr] + assert_match /"created_at":"\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{9}Z"/, Oj.dump(props, mode: :compat) + end yield props if block_given? end - def assert_auth_logged_with_clean_properties(auth, event_type) - assert_logged(auth, event_type) do |props| - ['old_attributes', 'new_attributes'].map { |k| props[k] }.compact - .each do |attributes| - refute_includes(attributes, 'api_token', - "auth log properties include sensitive API token") + def assert_logged_with_clean_properties(obj, event_type, excluded_attr) + assert_logged(obj, event_type) do |props| + ['old_attributes', 'new_attributes'].map do |logattr| + attributes = props[logattr] + next if attributes.nil? + refute_includes(attributes, excluded_attr, + "log #{logattr} includes #{excluded_attr}") end yield props if block_given? end @@ -115,7 +125,7 @@ class LogTest < ActiveSupport::TestCase orig_attrs = auth.attributes orig_attrs.delete 'api_token' auth.destroy - assert_logged(auth, :destroy) do |props| + assert_logged(auth, :delete) do |props| assert_equal(orig_etag, props['old_etag'], "destroyed auth etag mismatch") assert_equal(orig_attrs, props['old_attributes'], "destroyed auth attributes mismatch") @@ -224,12 +234,12 @@ class LogTest < ActiveSupport::TestCase auth.user = users(:spectator) auth.api_client = api_clients(:untrusted) auth.save! - assert_auth_logged_with_clean_properties(auth, :create) + assert_logged_with_clean_properties(auth, :create, 'api_token') auth.expires_at = Time.now auth.save! - assert_auth_logged_with_clean_properties(auth, :update) + assert_logged_with_clean_properties(auth, :update, 'api_token') auth.destroy - assert_auth_logged_with_clean_properties(auth, :destroy) + assert_logged_with_clean_properties(auth, :delete, 'api_token') end test "use ownership and permission links to determine which logs a user can see" do @@ -252,7 +262,8 @@ class LogTest < ActiveSupport::TestCase :crunchstat_for_running_job] # log & job owned by active c = Log.readable_by(users(:spectator)).order("id asc").each.to_a - assert_log_result c, known_logs, [:admin_changes_specimen, # owned by spectator + assert_log_result c, known_logs, [:noop, # object_uuid is spectator + :admin_changes_specimen, # object_uuid is a specimen owned by spectator :system_adds_baz] # readable via 'all users' group end @@ -261,7 +272,7 @@ class LogTest < ActiveSupport::TestCase # appear too, but only if they are _not_ listed in known_logs # (i.e., we do not make any assertions about logs not mentioned in # either "known" or "expected".) - result_ids = result.collect &:id + result_ids = result.collect(&:id) expected_logs.each do |want| assert_includes result_ids, logs(want).id end @@ -269,4 +280,117 @@ class LogTest < ActiveSupport::TestCase refute_includes result_ids, logs(notwant).id end end + + test "non-empty configuration.unlogged_attributes" do + Rails.configuration.AuditLogs.UnloggedAttributes = ["manifest_text"] + txt = ". acbd18db4cc2f85cedef654fccc4a4d8+3 0:3:foo\n" + + act_as_system_user do + coll = Collection.create(manifest_text: txt) + assert_logged_with_clean_properties(coll, :create, 'manifest_text') + coll.name = "testing" + coll.save! + assert_logged_with_clean_properties(coll, :update, 'manifest_text') + coll.destroy + assert_logged_with_clean_properties(coll, :delete, 'manifest_text') + end + end + + test "empty configuration.unlogged_attributes" do + Rails.configuration.AuditLogs.UnloggedAttributes = [] + txt = ". acbd18db4cc2f85cedef654fccc4a4d8+3 0:3:foo\n" + + act_as_system_user do + coll = Collection.create(manifest_text: txt) + assert_logged(coll, :create) do |props| + assert_equal(txt, props['new_attributes']['manifest_text']) + end + coll.update_attributes!(name: "testing") + assert_logged(coll, :update) do |props| + assert_equal(txt, props['old_attributes']['manifest_text']) + assert_equal(txt, props['new_attributes']['manifest_text']) + end + coll.destroy + assert_logged(coll, :delete) do |props| + assert_equal(txt, props['old_attributes']['manifest_text']) + end + end + end + + def assert_no_logs_deleted + logs_before = Log.unscoped.all.count + yield + assert_equal logs_before, Log.unscoped.all.count + end + + def remaining_audit_logs + Log.unscoped.where('event_type in (?)', %w(create update destroy delete)) + end + + # Default settings should not delete anything -- some sites rely on + # the original "keep everything forever" behavior. + test 'retain old audit logs with default settings' do + assert_no_logs_deleted do + AuditLogs.delete_old( + max_age: Rails.configuration.AuditLogs.MaxAge, + max_batch: Rails.configuration.AuditLogs.MaxDeleteBatch) + end + end + + # Batch size 0 should retain all logs -- even if max_age is very + # short, and even if the default settings (and associated test) have + # changed. + test 'retain old audit logs with max_audit_log_delete_batch=0' do + assert_no_logs_deleted do + AuditLogs.delete_old(max_age: 1, max_batch: 0) + end + end + + # We recommend a more conservative age of 5 minutes for production, + # but 3 minutes suits our test data better (and is test-worthy in + # that it's expected to work correctly in production). + test 'delete old audit logs with production settings' do + initial_log_count = Log.unscoped.all.count + AuditLogs.delete_old(max_age: 180, max_batch: 100000) + assert_operator remaining_audit_logs.count, :<, initial_log_count + end + + test 'delete all audit logs in multiple batches' do + AuditLogs.delete_old(max_age: 0.00001, max_batch: 2) + assert_equal [], remaining_audit_logs.collect(&:uuid) + end + + test 'delete old audit logs in thread' do + begin + Rails.configuration.AuditLogs.MaxAge = 20 + Rails.configuration.AuditLogs.MaxDeleteBatch = 100000 + Rails.cache.delete 'AuditLogs' + initial_log_count = Log.unscoped.all.count + 1 + act_as_system_user do + Log.create!() + initial_log_count += 1 + end + deadline = Time.now + 10 + while remaining_audit_logs.count == initial_log_count + if Time.now > deadline + raise "timed out" + end + sleep 0.1 + end + assert_operator remaining_audit_logs.count, :<, initial_log_count + ensure + # The test framework rolls back our transactions, but that + # doesn't undo the deletes we did from separate threads. + ActiveRecord::Base.connection.exec_query 'ROLLBACK' + Thread.new do + begin + dc = DatabaseController.new + dc.define_singleton_method :render do |*args| end + dc.reset + ensure + ActiveRecord::Base.connection.close + end + end.join + end + end end