services/api/test/unit/log_test.rb

   1 require 'test_helper'
   2
   3 class LogTest < ActiveSupport::TestCase
   4   include CurrentApiClient
   5   include DbCurrentTime
   6
   7   EVENT_TEST_METHODS = {
   8     :create => [:created_at, :assert_nil, :assert_not_nil],
   9     :update => [:modified_at, :assert_not_nil, :assert_not_nil],
  10     :destroy => [nil, :assert_not_nil, :assert_nil],
  11   }
  12
  13   def setup
  14     @start_time = db_current_time
  15     @log_count = 1
  16   end
  17
  18   def assert_properties(test_method, event, props, *keys)
  19     verb = (test_method == :assert_nil) ? 'have nil' : 'define'
  20     keys.each do |prop_name|
  21       assert_includes(props, prop_name, "log properties missing #{prop_name}")
  22       self.send(test_method, props[prop_name],
  23                 "#{event.to_s} log should #{verb} #{prop_name}")
  24     end
  25   end
  26
  27   def get_logs_about(thing)
  28     Log.where(object_uuid: thing.uuid).order("created_at ASC").all
  29   end
  30
  31   def assert_logged(thing, event_type)
  32     logs = get_logs_about(thing)
  33     assert_equal(@log_count, logs.size, "log count mismatch")
  34     @log_count += 1
  35     log = logs.last
  36     props = log.properties
  37     assert_equal(current_user.andand.uuid, log.owner_uuid,
  38                  "log is not owned by current user")
  39     assert_equal(current_user.andand.uuid, log.modified_by_user_uuid,
  40                  "log is not 'modified by' current user")
  41     assert_equal(current_api_client.andand.uuid, log.modified_by_client_uuid,
  42                  "log is not 'modified by' current client")
  43     assert_equal(thing.uuid, log.object_uuid, "log UUID mismatch")
  44     assert_equal(event_type.to_s, log.event_type, "log event type mismatch")
  45     time_method, old_props_test, new_props_test = EVENT_TEST_METHODS[event_type]
  46     if time_method.nil? or (timestamp = thing.send(time_method)).nil?
  47       assert(log.event_at >= @start_time, "log timestamp too old")
  48     else
  49       assert_in_delta(timestamp, log.event_at, 1, "log timestamp mismatch")
  50     end
  51     assert_properties(old_props_test, event_type, props,
  52                       'old_etag', 'old_attributes')
  53     assert_properties(new_props_test, event_type, props,
  54                       'new_etag', 'new_attributes')
  55     yield props if block_given?
  56   end
  57
  58   def assert_auth_logged_with_clean_properties(auth, event_type)
  59     assert_logged(auth, event_type) do |props|
  60       ['old_attributes', 'new_attributes'].map { |k| props[k] }.compact
  61         .each do |attributes|
  62         refute_includes(attributes, 'api_token',
  63                         "auth log properties include sensitive API token")
  64       end
  65       yield props if block_given?
  66     end
  67   end
  68
  69   test "creating a user makes a log" do
  70     set_user_from_auth :admin_trustedclient
  71     u = User.new(first_name: "Log", last_name: "Test")
  72     u.save!
  73     assert_logged(u, :create) do |props|
  74       assert_equal(u.etag, props['new_etag'], "new user etag mismatch")
  75       assert_equal(u.first_name, props['new_attributes']['first_name'],
  76                    "new user first name mismatch")
  77       assert_equal(u.last_name, props['new_attributes']['last_name'],
  78                    "new user first name mismatch")
  79     end
  80   end
  81
  82   test "updating a virtual machine makes a log" do
  83     set_user_from_auth :admin_trustedclient
  84     vm = virtual_machines(:testvm)
  85     orig_etag = vm.etag
  86     vm.hostname = 'testvm.testshell'
  87     vm.save!
  88     assert_logged(vm, :update) do |props|
  89       assert_equal(orig_etag, props['old_etag'], "updated VM old etag mismatch")
  90       assert_equal(vm.etag, props['new_etag'], "updated VM new etag mismatch")
  91       assert_equal('testvm.shell', props['old_attributes']['hostname'],
  92                    "updated VM old name mismatch")
  93       assert_equal('testvm.testshell', props['new_attributes']['hostname'],
  94                    "updated VM new name mismatch")
  95     end
  96   end
  97
  98   test "old_attributes preserves values deep inside a hash" do
  99     set_user_from_auth :active
 100     it = specimens(:owned_by_active_user)
 101     it.properties = {'foo' => {'bar' => ['baz', 'qux', {'quux' => 'bleat'}]}}
 102     it.save!
 103     @log_count += 1
 104     it.properties['foo']['bar'][2]['quux'] = 'blert'
 105     it.save!
 106     assert_logged it, :update do |props|
 107       assert_equal 'bleat', props['old_attributes']['properties']['foo']['bar'][2]['quux']
 108       assert_equal 'blert', props['new_attributes']['properties']['foo']['bar'][2]['quux']
 109     end
 110   end
 111
 112   test "destroying an authorization makes a log" do
 113     set_user_from_auth :admin_trustedclient
 114     auth = api_client_authorizations(:spectator)
 115     orig_etag = auth.etag
 116     orig_attrs = auth.attributes
 117     orig_attrs.delete 'api_token'
 118     auth.destroy
 119     assert_logged(auth, :destroy) do |props|
 120       assert_equal(orig_etag, props['old_etag'], "destroyed auth etag mismatch")
 121       assert_equal(orig_attrs, props['old_attributes'],
 122                    "destroyed auth attributes mismatch")
 123     end
 124   end
 125
 126   test "saving an unchanged client still makes a log" do
 127     set_user_from_auth :admin_trustedclient
 128     client = api_clients(:untrusted)
 129     client.is_trusted = client.is_trusted
 130     client.save!
 131     assert_logged(client, :update) do |props|
 132       ['old', 'new'].each do |age|
 133         assert_equal(client.etag, props["#{age}_etag"],
 134                      "unchanged client #{age} etag mismatch")
 135         assert_equal(client.attributes, props["#{age}_attributes"],
 136                      "unchanged client #{age} attributes mismatch")
 137       end
 138     end
 139   end
 140
 141   test "updating a group twice makes two logs" do
 142     set_user_from_auth :admin_trustedclient
 143     group = groups(:empty_lonely_group)
 144     name1 = group.name
 145     name2 = "#{name1} under test"
 146     group.name = name2
 147     group.save!
 148     assert_logged(group, :update) do |props|
 149       assert_equal(name1, props['old_attributes']['name'],
 150                    "group start name mismatch")
 151       assert_equal(name2, props['new_attributes']['name'],
 152                    "group updated name mismatch")
 153     end
 154     group.name = name1
 155     group.save!
 156     assert_logged(group, :update) do |props|
 157       assert_equal(name2, props['old_attributes']['name'],
 158                    "group pre-revert name mismatch")
 159       assert_equal(name1, props['new_attributes']['name'],
 160                    "group final name mismatch")
 161     end
 162   end
 163
 164   test "making a log doesn't get logged" do
 165     set_user_from_auth :active_trustedclient
 166     log = Log.new
 167     log.save!
 168     assert_equal(0, get_logs_about(log).size, "made a Log about a Log")
 169   end
 170
 171   test "non-admins can't modify or delete logs" do
 172     set_user_from_auth :active_trustedclient
 173     log = Log.new(summary: "immutable log test")
 174     assert_nothing_raised { log.save! }
 175     log.summary = "log mutation test should fail"
 176     assert_raise(ArvadosModel::PermissionDeniedError) { log.save! }
 177     assert_raise(ArvadosModel::PermissionDeniedError) { log.destroy }
 178   end
 179
 180   test "admins can modify and delete logs" do
 181     set_user_from_auth :admin_trustedclient
 182     log = Log.new(summary: "admin log mutation test")
 183     assert_nothing_raised { log.save! }
 184     log.summary = "admin mutated log test"
 185     assert_nothing_raised { log.save! }
 186     assert_nothing_raised { log.destroy }
 187   end
 188
 189   test "failure saving log causes failure saving object" do
 190     Log.class_eval do
 191       alias_method :_orig_validations, :perform_validations
 192       def perform_validations(options)
 193         false
 194       end
 195     end
 196     begin
 197       set_user_from_auth :active_trustedclient
 198       user = users(:active)
 199       user.first_name = 'Test'
 200       assert_raise(ActiveRecord::RecordInvalid) { user.save! }
 201     ensure
 202       Log.class_eval do
 203         alias_method :perform_validations, :_orig_validations
 204       end
 205     end
 206   end
 207
 208   test "don't log changes only to ApiClientAuthorization.last_used_*" do
 209     set_user_from_auth :admin_trustedclient
 210     auth = api_client_authorizations(:spectator)
 211     start_log_count = get_logs_about(auth).size
 212     auth.last_used_at = Time.now
 213     auth.last_used_by_ip_address = '::1'
 214     auth.save!
 215     assert_equal(start_log_count, get_logs_about(auth).size,
 216                  "log count changed after 'using' ApiClientAuthorization")
 217     auth.created_by_ip_address = '::1'
 218     auth.save!
 219     assert_logged(auth, :update)
 220   end
 221
 222   test "token isn't included in ApiClientAuthorization logs" do
 223     set_user_from_auth :admin_trustedclient
 224     auth = ApiClientAuthorization.new
 225     auth.user = users(:spectator)
 226     auth.api_client = api_clients(:untrusted)
 227     auth.save!
 228     assert_auth_logged_with_clean_properties(auth, :create)
 229     auth.expires_at = Time.now
 230     auth.save!
 231     assert_auth_logged_with_clean_properties(auth, :update)
 232     auth.destroy
 233     assert_auth_logged_with_clean_properties(auth, :destroy)
 234   end
 235
 236   test "use ownership and permission links to determine which logs a user can see" do
 237     c = Log.readable_by(users(:admin)).order("id asc").each.to_a
 238     assert_equal 6, c.size
 239     assert_equal 1, c[0].id # no-op
 240     assert_equal 2, c[1].id # admin changes repository foo, which is owned by active user
 241     assert_equal 3, c[2].id # admin changes specimen owned_by_spectator
 242     assert_equal 4, c[3].id # foo collection added, readable by active through link
 243     assert_equal 5, c[4].id # baz collection added, readable by active and spectator through group 'all users' group membership
 244     assert_equal 6, c[5].id # log_owned_by_active
 245
 246     c = Log.readable_by(users(:active)).order("id asc").each.to_a
 247     assert_equal 4, c.size
 248     assert_equal 2, c[0].id # admin changes repository foo, which is owned by active user
 249     assert_equal 4, c[1].id # foo collection added, readable by active through link
 250     assert_equal 5, c[2].id # baz collection added, readable by active and spectator through group 'all users' group membership
 251     assert_equal 6, c[3].id # log_owned_by_active
 252
 253     c = Log.readable_by(users(:spectator)).order("id asc").each.to_a
 254     assert_equal 2, c.size
 255     assert_equal 3, c[0].id # admin changes specimen owned_by_spectator
 256     assert_equal 5, c[1].id # baz collection added, readable by active and spectator through group 'all users' group membership
 257   end
 258 end