services/api/test/unit/log_test.rb

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