api: Don't include API tokens in logs.
[arvados.git] / 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     :destroy => [nil, :assert_not_nil, :assert_nil],
10   }
11
12   def setup
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.kind, log.object_kind, "log kind mismatch")
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   def set_user_from_auth(auth_name)
70     client_auth = api_client_authorizations(auth_name)
71     Thread.current[:api_client_authorization] = client_auth
72     Thread.current[:api_client] = client_auth.api_client
73     Thread.current[:user] = client_auth.user
74   end
75
76   test "creating a user makes a log" do
77     set_user_from_auth :admin_trustedclient
78     u = User.new(first_name: "Log", last_name: "Test")
79     u.save!
80     assert_logged(u, :create) do |props|
81       assert_equal(u.etag, props['new_etag'], "new user etag mismatch")
82       assert_equal(u.first_name, props['new_attributes']['first_name'],
83                    "new user first name mismatch")
84       assert_equal(u.last_name, props['new_attributes']['last_name'],
85                    "new user first name mismatch")
86     end
87   end
88
89   test "updating a virtual machine makes a log" do
90     set_user_from_auth :admin_trustedclient
91     vm = virtual_machines(:testvm)
92     orig_etag = vm.etag
93     vm.hostname = 'testvm.testshell'
94     vm.save!
95     assert_logged(vm, :update) do |props|
96       assert_equal(orig_etag, props['old_etag'], "updated VM old etag mismatch")
97       assert_equal(vm.etag, props['new_etag'], "updated VM new etag mismatch")
98       assert_equal('testvm.shell', props['old_attributes']['hostname'],
99                    "updated VM old name mismatch")
100       assert_equal('testvm.testshell', props['new_attributes']['hostname'],
101                    "updated VM new name mismatch")
102     end
103   end
104
105   test "destroying an authorization makes a log" do
106     set_user_from_auth :admin_trustedclient
107     auth = api_client_authorizations(:spectator)
108     orig_etag = auth.etag
109     orig_attrs = auth.attributes
110     orig_attrs.delete 'api_token'
111     auth.destroy
112     assert_logged(auth, :destroy) do |props|
113       assert_equal(orig_etag, props['old_etag'], "destroyed auth etag mismatch")
114       assert_equal(orig_attrs, props['old_attributes'],
115                    "destroyed auth attributes mismatch")
116     end
117   end
118
119   test "saving an unchanged client still makes a log" do
120     set_user_from_auth :admin_trustedclient
121     client = api_clients(:untrusted)
122     client.is_trusted = client.is_trusted
123     client.save!
124     assert_logged(client, :update) do |props|
125       ['old', 'new'].each do |age|
126         assert_equal(client.etag, props["#{age}_etag"],
127                      "unchanged client #{age} etag mismatch")
128         assert_equal(client.attributes, props["#{age}_attributes"],
129                      "unchanged client #{age} attributes mismatch")
130       end
131     end
132   end
133
134   test "updating a group twice makes two logs" do
135     set_user_from_auth :admin_trustedclient
136     group = groups(:empty_lonely_group)
137     name1 = group.name
138     name2 = "#{name1} under test"
139     group.name = name2
140     group.save!
141     assert_logged(group, :update) do |props|
142       assert_equal(name1, props['old_attributes']['name'],
143                    "group start name mismatch")
144       assert_equal(name2, props['new_attributes']['name'],
145                    "group updated name mismatch")
146     end
147     group.name = name1
148     group.save!
149     assert_logged(group, :update) do |props|
150       assert_equal(name2, props['old_attributes']['name'],
151                    "group pre-revert name mismatch")
152       assert_equal(name1, props['new_attributes']['name'],
153                    "group final name mismatch")
154     end
155   end
156
157   test "making a log doesn't get logged" do
158     set_user_from_auth :active_trustedclient
159     log = Log.new
160     log.save!
161     assert_equal(0, get_logs_about(log).size, "made a Log about a Log")
162   end
163
164   test "non-admins can't modify or delete logs" do
165     set_user_from_auth :active_trustedclient
166     log = Log.new(summary: "immutable log test")
167     assert_nothing_raised { log.save! }
168     log.summary = "log mutation test should fail"
169     assert_raise(ArvadosModel::PermissionDeniedError) { log.save! }
170     assert_raise(ArvadosModel::PermissionDeniedError) { log.destroy }
171   end
172
173   test "admins can modify and delete logs" do
174     set_user_from_auth :admin_trustedclient
175     log = Log.new(summary: "admin log mutation test")
176     assert_nothing_raised { log.save! }
177     log.summary = "admin mutated log test"
178     assert_nothing_raised { log.save! }
179     assert_nothing_raised { log.destroy }
180   end
181
182   test "failure saving log causes failure saving object" do
183     Log.class_eval do
184       alias_method :_orig_validations, :perform_validations
185       def perform_validations(options)
186         false
187       end
188     end
189     begin
190       set_user_from_auth :active_trustedclient
191       user = users(:active)
192       user.first_name = 'Test'
193       assert_raise(ActiveRecord::RecordInvalid) { user.save! }
194     ensure
195       Log.class_eval do
196         alias_method :perform_validations, :_orig_validations
197       end
198     end
199   end
200
201   test "don't log changes only to ApiClientAuthorization.last_used_*" do
202     set_user_from_auth :admin_trustedclient
203     auth = api_client_authorizations(:spectator)
204     start_log_count = get_logs_about(auth).size
205     auth.last_used_at = Time.now
206     auth.last_used_by_ip_address = '::1'
207     auth.save!
208     assert_equal(start_log_count, get_logs_about(auth).size,
209                  "log count changed after 'using' ApiClientAuthorization")
210     auth.created_by_ip_address = '::1'
211     auth.save!
212     assert_logged(auth, :update)
213   end
214
215   test "token isn't included in ApiClientAuthorization logs" do
216     set_user_from_auth :admin_trustedclient
217     auth = ApiClientAuthorization.new
218     auth.user = users(:spectator)
219     auth.api_client = api_clients(:untrusted)
220     auth.save!
221     assert_auth_logged_with_clean_properties(auth, :create)
222     auth.expires_at = Time.now
223     auth.save!
224     assert_auth_logged_with_clean_properties(auth, :update)
225     auth.destroy
226     assert_auth_logged_with_clean_properties(auth, :destroy)
227   end
228 end