X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/eb7227693e8847a65798afa7f7e8a4ffe8a199a4..1a7c5c627ca9cbbbc13e1c9710bbd6268c59b22a:/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 3876775916..66c8c8d923 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,27 +56,25 @@ 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 end - def set_user_from_auth(auth_name) - client_auth = api_client_authorizations(auth_name) - Thread.current[:api_client_authorization] = client_auth - Thread.current[:api_client] = client_auth.api_client - Thread.current[:user] = client_auth.user - end - test "creating a user makes a log" do set_user_from_auth :admin_trustedclient u = User.new(first_name: "Log", last_name: "Test") @@ -101,6 +104,20 @@ class LogTest < ActiveSupport::TestCase end end + test "old_attributes preserves values deep inside a hash" do + set_user_from_auth :active + it = specimens(:owned_by_active_user) + it.properties = {'foo' => {'bar' => ['baz', 'qux', {'quux' => 'bleat'}]}} + it.save! + @log_count += 1 + it.properties['foo']['bar'][2]['quux'] = 'blert' + it.save! + assert_logged it, :update do |props| + assert_equal 'bleat', props['old_attributes']['properties']['foo']['bar'][2]['quux'] + assert_equal 'blert', props['new_attributes']['properties']['foo']['bar'][2]['quux'] + end + end + test "destroying an authorization makes a log" do set_user_from_auth :admin_trustedclient auth = api_client_authorizations(:spectator) @@ -108,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") @@ -211,17 +228,171 @@ class LogTest < ActiveSupport::TestCase assert_logged(auth, :update) end + test "don't log changes only to Collection.preserve_version" do + set_user_from_auth :admin_trustedclient + col = collections(:collection_owned_by_active) + start_log_count = get_logs_about(col).size + assert_equal false, col.preserve_version + col.preserve_version = true + col.save! + assert_equal(start_log_count, get_logs_about(col).size, + "log count changed after updating Collection.preserve_version") + col.name = 'updated by admin' + col.save! + assert_logged(col, :update) + end + test "token isn't included in ApiClientAuthorization logs" do set_user_from_auth :admin_trustedclient auth = ApiClientAuthorization.new 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 + known_logs = [:noop, + :admin_changes_repository2, + :admin_changes_specimen, + :system_adds_foo_file, + :system_adds_baz, + :log_owned_by_active, + :crunchstat_for_running_job] + + c = Log.readable_by(users(:admin)).order("id asc").each.to_a + assert_log_result c, known_logs, known_logs + + c = Log.readable_by(users(:active)).order("id asc").each.to_a + assert_log_result c, known_logs, [:admin_changes_repository2, # owned by active + :system_adds_foo_file, # readable via link + :system_adds_baz, # readable via 'all users' group + :log_owned_by_active, # log owned by active + :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, [: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 + + def assert_log_result result, known_logs, expected_logs + # All of expected_logs must appear in result. Additional logs can + # 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) + expected_logs.each do |want| + assert_includes result_ids, logs(want).id + end + (known_logs - expected_logs).each do |notwant| + refute_includes result_ids, logs(notwant).id + end + end + + test "non-empty configuration.unlogged_attributes" do + Rails.configuration.AuditLogs.UnloggedAttributes = ConfigLoader.to_OrderedOptions({"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 = ConfigLoader.to_OrderedOptions({}) + 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 + assert logs_before > 0 + 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 = remaining_audit_logs.count + assert initial_log_count > 0 + 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 + assert remaining_audit_logs.count > 2 + 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 + Rails.configuration.AuditLogs.MaxAge = 20 + Rails.configuration.AuditLogs.MaxDeleteBatch = 100000 + Rails.cache.delete 'AuditLogs' + initial_audit_log_count = remaining_audit_logs.count + assert initial_audit_log_count > 0 + act_as_system_user do + Log.create!() + end + deadline = Time.now + 10 + while remaining_audit_logs.count == initial_audit_log_count + if Time.now > deadline + raise "timed out" + end + sleep 0.1 + end + assert_operator remaining_audit_logs.count, :<, initial_audit_log_count end end