Merge branch 'master' into 16811-public-favs
[arvados.git] / services / api / test / unit / log_test.rb
index 28980335788414076a642c221f39a25fac6cbd65..76d78f9eaa6cf14ebd83b8b7b138e3f94c69dff5 100644 (file)
@@ -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
@@ -39,7 +44,6 @@ class LogTest < ActiveSupport::TestCase
                  "log is not 'modified by' current user")
     assert_equal(current_api_client.andand.uuid, log.modified_by_client_uuid,
                  "log is not 'modified by' current client")
-    assert_equal(thing.kind, log.object_kind, "log kind mismatch")
     assert_equal(thing.uuid, log.object_uuid, "log UUID mismatch")
     assert_equal(event_type.to_s, log.event_type, "log event type mismatch")
     time_method, old_props_test, new_props_test = EVENT_TEST_METHODS[event_type]
@@ -52,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")
@@ -102,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)
@@ -109,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")
@@ -218,11 +234,151 @@ 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
+    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