18071: Use dblock to prevent multiple dispatchers from competing.
[arvados.git] / lib / controller / handler_test.go
1 // Copyright (C) The Arvados Authors. All rights reserved.
2 //
3 // SPDX-License-Identifier: AGPL-3.0
4
5 package controller
6
7 import (
8         "bytes"
9         "context"
10         "crypto/tls"
11         "encoding/json"
12         "io"
13         "io/ioutil"
14         "net/http"
15         "net/http/httptest"
16         "net/url"
17         "os"
18         "strings"
19         "testing"
20         "time"
21
22         "git.arvados.org/arvados.git/lib/controller/rpc"
23         "git.arvados.org/arvados.git/sdk/go/arvados"
24         "git.arvados.org/arvados.git/sdk/go/arvadostest"
25         "git.arvados.org/arvados.git/sdk/go/auth"
26         "git.arvados.org/arvados.git/sdk/go/ctxlog"
27         "git.arvados.org/arvados.git/sdk/go/httpserver"
28         "github.com/prometheus/client_golang/prometheus"
29         check "gopkg.in/check.v1"
30 )
31
32 // Gocheck boilerplate
33 func Test(t *testing.T) {
34         check.TestingT(t)
35 }
36
37 var _ = check.Suite(&HandlerSuite{})
38
39 type HandlerSuite struct {
40         cluster *arvados.Cluster
41         handler *Handler
42         logbuf  *bytes.Buffer
43         ctx     context.Context
44         cancel  context.CancelFunc
45 }
46
47 func (s *HandlerSuite) SetUpTest(c *check.C) {
48         s.logbuf = &bytes.Buffer{}
49         s.ctx, s.cancel = context.WithCancel(context.Background())
50         s.ctx = ctxlog.Context(s.ctx, ctxlog.New(io.MultiWriter(os.Stderr, s.logbuf), "json", "debug"))
51         s.cluster = &arvados.Cluster{
52                 ClusterID:  "zzzzz",
53                 PostgreSQL: integrationTestCluster().PostgreSQL,
54         }
55         s.cluster.API.RequestTimeout = arvados.Duration(5 * time.Minute)
56         s.cluster.TLS.Insecure = true
57         arvadostest.SetServiceURL(&s.cluster.Services.RailsAPI, "https://"+os.Getenv("ARVADOS_TEST_API_HOST"))
58         arvadostest.SetServiceURL(&s.cluster.Services.Controller, "http://localhost:/")
59         s.handler = newHandler(s.ctx, s.cluster, "", prometheus.NewRegistry()).(*Handler)
60 }
61
62 func (s *HandlerSuite) TearDownTest(c *check.C) {
63         s.cancel()
64 }
65
66 func (s *HandlerSuite) TestConfigExport(c *check.C) {
67         s.cluster.ManagementToken = "secret"
68         s.cluster.SystemRootToken = "secret"
69         s.cluster.Collections.BlobSigning = true
70         s.cluster.Collections.BlobSigningTTL = arvados.Duration(23 * time.Second)
71         for _, method := range []string{"GET", "OPTIONS"} {
72                 req := httptest.NewRequest(method, "/arvados/v1/config", nil)
73                 resp := httptest.NewRecorder()
74                 s.handler.ServeHTTP(resp, req)
75                 c.Log(resp.Body.String())
76                 if !c.Check(resp.Code, check.Equals, http.StatusOK) {
77                         continue
78                 }
79                 c.Check(resp.Header().Get("Access-Control-Allow-Origin"), check.Equals, `*`)
80                 c.Check(resp.Header().Get("Access-Control-Allow-Methods"), check.Matches, `.*\bGET\b.*`)
81                 c.Check(resp.Header().Get("Access-Control-Allow-Headers"), check.Matches, `.+`)
82                 if method == "OPTIONS" {
83                         c.Check(resp.Body.String(), check.HasLen, 0)
84                         continue
85                 }
86                 var cluster arvados.Cluster
87                 err := json.Unmarshal(resp.Body.Bytes(), &cluster)
88                 c.Check(err, check.IsNil)
89                 c.Check(cluster.ManagementToken, check.Equals, "")
90                 c.Check(cluster.SystemRootToken, check.Equals, "")
91                 c.Check(cluster.Collections.BlobSigning, check.Equals, true)
92                 c.Check(cluster.Collections.BlobSigningTTL, check.Equals, arvados.Duration(23*time.Second))
93         }
94 }
95
96 func (s *HandlerSuite) TestVocabularyExport(c *check.C) {
97         voc := `{
98                 "strict_tags": false,
99                 "tags": {
100                         "IDTAGIMPORTANCE": {
101                                 "strict": false,
102                                 "labels": [{"label": "Importance"}],
103                                 "values": {
104                                         "HIGH": {
105                                                 "labels": [{"label": "High"}]
106                                         },
107                                         "LOW": {
108                                                 "labels": [{"label": "Low"}]
109                                         }
110                                 }
111                         }
112                 }
113         }`
114         f, err := os.CreateTemp("", "test-vocabulary-*.json")
115         c.Assert(err, check.IsNil)
116         defer os.Remove(f.Name())
117         _, err = f.WriteString(voc)
118         c.Assert(err, check.IsNil)
119         f.Close()
120         s.cluster.API.VocabularyPath = f.Name()
121         for _, method := range []string{"GET", "OPTIONS"} {
122                 c.Log(c.TestName()+" ", method)
123                 req := httptest.NewRequest(method, "/arvados/v1/vocabulary", nil)
124                 resp := httptest.NewRecorder()
125                 s.handler.ServeHTTP(resp, req)
126                 c.Log(resp.Body.String())
127                 if !c.Check(resp.Code, check.Equals, http.StatusOK) {
128                         continue
129                 }
130                 c.Check(resp.Header().Get("Access-Control-Allow-Origin"), check.Equals, `*`)
131                 c.Check(resp.Header().Get("Access-Control-Allow-Methods"), check.Matches, `.*\bGET\b.*`)
132                 c.Check(resp.Header().Get("Access-Control-Allow-Headers"), check.Matches, `.+`)
133                 if method == "OPTIONS" {
134                         c.Check(resp.Body.String(), check.HasLen, 0)
135                         continue
136                 }
137                 var expectedVoc, receivedVoc *arvados.Vocabulary
138                 err := json.Unmarshal([]byte(voc), &expectedVoc)
139                 c.Check(err, check.IsNil)
140                 err = json.Unmarshal(resp.Body.Bytes(), &receivedVoc)
141                 c.Check(err, check.IsNil)
142                 c.Check(receivedVoc, check.DeepEquals, expectedVoc)
143         }
144 }
145
146 func (s *HandlerSuite) TestVocabularyFailedCheckStatus(c *check.C) {
147         voc := `{
148                 "strict_tags": false,
149                 "tags": {
150                         "IDTAGIMPORTANCE": {
151                                 "strict": true,
152                                 "labels": [{"label": "Importance"}],
153                                 "values": {
154                                         "HIGH": {
155                                                 "labels": [{"label": "High"}]
156                                         },
157                                         "LOW": {
158                                                 "labels": [{"label": "Low"}]
159                                         }
160                                 }
161                         }
162                 }
163         }`
164         f, err := os.CreateTemp("", "test-vocabulary-*.json")
165         c.Assert(err, check.IsNil)
166         defer os.Remove(f.Name())
167         _, err = f.WriteString(voc)
168         c.Assert(err, check.IsNil)
169         f.Close()
170         s.cluster.API.VocabularyPath = f.Name()
171
172         req := httptest.NewRequest("POST", "/arvados/v1/collections",
173                 strings.NewReader(`{
174                         "collection": {
175                                 "properties": {
176                                         "IDTAGIMPORTANCE": "Critical"
177                                 }
178                         }
179                 }`))
180         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
181         req.Header.Set("Content-type", "application/json")
182
183         resp := httptest.NewRecorder()
184         s.handler.ServeHTTP(resp, req)
185         c.Log(resp.Body.String())
186         c.Assert(resp.Code, check.Equals, http.StatusBadRequest)
187         var jresp httpserver.ErrorResponse
188         err = json.Unmarshal(resp.Body.Bytes(), &jresp)
189         c.Check(err, check.IsNil)
190         c.Assert(len(jresp.Errors), check.Equals, 1)
191         c.Check(jresp.Errors[0], check.Matches, `.*tag value.*is not valid for key.*`)
192 }
193
194 func (s *HandlerSuite) TestProxyDiscoveryDoc(c *check.C) {
195         req := httptest.NewRequest("GET", "/discovery/v1/apis/arvados/v1/rest", nil)
196         resp := httptest.NewRecorder()
197         s.handler.ServeHTTP(resp, req)
198         c.Check(resp.Code, check.Equals, http.StatusOK)
199         var dd arvados.DiscoveryDocument
200         err := json.Unmarshal(resp.Body.Bytes(), &dd)
201         c.Check(err, check.IsNil)
202         c.Check(dd.BlobSignatureTTL, check.Not(check.Equals), int64(0))
203         c.Check(dd.BlobSignatureTTL > 0, check.Equals, true)
204         c.Check(len(dd.Resources), check.Not(check.Equals), 0)
205         c.Check(len(dd.Schemas), check.Not(check.Equals), 0)
206 }
207
208 // Handler should give up and exit early if request context is
209 // cancelled due to client hangup, httpserver.HandlerWithDeadline,
210 // etc.
211 func (s *HandlerSuite) TestRequestCancel(c *check.C) {
212         ctx, cancel := context.WithCancel(context.Background())
213         req := httptest.NewRequest("GET", "/discovery/v1/apis/arvados/v1/rest", nil).WithContext(ctx)
214         resp := httptest.NewRecorder()
215         cancel()
216         s.handler.ServeHTTP(resp, req)
217         c.Check(resp.Code, check.Equals, http.StatusBadGateway)
218         var jresp httpserver.ErrorResponse
219         err := json.Unmarshal(resp.Body.Bytes(), &jresp)
220         c.Check(err, check.IsNil)
221         c.Assert(len(jresp.Errors), check.Equals, 1)
222         c.Check(jresp.Errors[0], check.Matches, `.*context canceled`)
223 }
224
225 func (s *HandlerSuite) TestProxyWithoutToken(c *check.C) {
226         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
227         resp := httptest.NewRecorder()
228         s.handler.ServeHTTP(resp, req)
229         c.Check(resp.Code, check.Equals, http.StatusUnauthorized)
230         jresp := map[string]interface{}{}
231         err := json.Unmarshal(resp.Body.Bytes(), &jresp)
232         c.Check(err, check.IsNil)
233         c.Check(jresp["errors"], check.FitsTypeOf, []interface{}{})
234 }
235
236 func (s *HandlerSuite) TestProxyWithToken(c *check.C) {
237         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
238         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
239         resp := httptest.NewRecorder()
240         s.handler.ServeHTTP(resp, req)
241         c.Check(resp.Code, check.Equals, http.StatusOK)
242         var u arvados.User
243         err := json.Unmarshal(resp.Body.Bytes(), &u)
244         c.Check(err, check.IsNil)
245         c.Check(u.UUID, check.Equals, arvadostest.ActiveUserUUID)
246 }
247
248 func (s *HandlerSuite) TestProxyWithTokenInRequestBody(c *check.C) {
249         req := httptest.NewRequest("POST", "/arvados/v1/users/current", strings.NewReader(url.Values{
250                 "_method":   {"GET"},
251                 "api_token": {arvadostest.ActiveToken},
252         }.Encode()))
253         req.Header.Set("Content-type", "application/x-www-form-urlencoded")
254         resp := httptest.NewRecorder()
255         s.handler.ServeHTTP(resp, req)
256         c.Check(resp.Code, check.Equals, http.StatusOK)
257         var u arvados.User
258         err := json.Unmarshal(resp.Body.Bytes(), &u)
259         c.Check(err, check.IsNil)
260         c.Check(u.UUID, check.Equals, arvadostest.ActiveUserUUID)
261 }
262
263 func (s *HandlerSuite) TestProxyNotFound(c *check.C) {
264         req := httptest.NewRequest("GET", "/arvados/v1/xyzzy", nil)
265         resp := httptest.NewRecorder()
266         s.handler.ServeHTTP(resp, req)
267         c.Check(resp.Code, check.Equals, http.StatusNotFound)
268         jresp := map[string]interface{}{}
269         err := json.Unmarshal(resp.Body.Bytes(), &jresp)
270         c.Check(err, check.IsNil)
271         c.Check(jresp["errors"], check.FitsTypeOf, []interface{}{})
272 }
273
274 func (s *HandlerSuite) TestLogoutGoogle(c *check.C) {
275         s.cluster.Login.Google.Enable = true
276         s.cluster.Login.Google.ClientID = "test"
277         req := httptest.NewRequest("GET", "https://0.0.0.0:1/logout?return_to=https://example.com/foo", nil)
278         resp := httptest.NewRecorder()
279         s.handler.ServeHTTP(resp, req)
280         if !c.Check(resp.Code, check.Equals, http.StatusFound) {
281                 c.Log(resp.Body.String())
282         }
283         c.Check(resp.Header().Get("Location"), check.Equals, "https://example.com/foo")
284 }
285
286 func (s *HandlerSuite) TestValidateV1APIToken(c *check.C) {
287         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
288         user, ok, err := s.handler.validateAPItoken(req, arvadostest.ActiveToken)
289         c.Assert(err, check.IsNil)
290         c.Check(ok, check.Equals, true)
291         c.Check(user.Authorization.UUID, check.Equals, arvadostest.ActiveTokenUUID)
292         c.Check(user.Authorization.APIToken, check.Equals, arvadostest.ActiveToken)
293         c.Check(user.Authorization.Scopes, check.DeepEquals, []string{"all"})
294         c.Check(user.UUID, check.Equals, arvadostest.ActiveUserUUID)
295 }
296
297 func (s *HandlerSuite) TestValidateV2APIToken(c *check.C) {
298         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
299         user, ok, err := s.handler.validateAPItoken(req, arvadostest.ActiveTokenV2)
300         c.Assert(err, check.IsNil)
301         c.Check(ok, check.Equals, true)
302         c.Check(user.Authorization.UUID, check.Equals, arvadostest.ActiveTokenUUID)
303         c.Check(user.Authorization.APIToken, check.Equals, arvadostest.ActiveToken)
304         c.Check(user.Authorization.Scopes, check.DeepEquals, []string{"all"})
305         c.Check(user.UUID, check.Equals, arvadostest.ActiveUserUUID)
306         c.Check(user.Authorization.TokenV2(), check.Equals, arvadostest.ActiveTokenV2)
307 }
308
309 func (s *HandlerSuite) TestValidateRemoteToken(c *check.C) {
310         saltedToken, err := auth.SaltToken(arvadostest.ActiveTokenV2, "abcde")
311         c.Assert(err, check.IsNil)
312         for _, trial := range []struct {
313                 code  int
314                 token string
315         }{
316                 {http.StatusOK, saltedToken},
317                 {http.StatusUnauthorized, "bogus"},
318         } {
319                 req := httptest.NewRequest("GET", "https://0.0.0.0:1/arvados/v1/users/current?remote=abcde", nil)
320                 req.Header.Set("Authorization", "Bearer "+trial.token)
321                 resp := httptest.NewRecorder()
322                 s.handler.ServeHTTP(resp, req)
323                 if !c.Check(resp.Code, check.Equals, trial.code) {
324                         c.Logf("HTTP %d: %s", resp.Code, resp.Body.String())
325                 }
326         }
327 }
328
329 func (s *HandlerSuite) TestLogTokenUUID(c *check.C) {
330         req := httptest.NewRequest("GET", "https://0.0.0.0/arvados/v1/users/current", nil)
331         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveTokenV2)
332         req = req.WithContext(s.ctx)
333         resp := httptest.NewRecorder()
334         httpserver.LogRequests(s.handler).ServeHTTP(resp, req)
335         c.Check(resp.Code, check.Equals, http.StatusOK)
336         c.Check(s.logbuf.String(), check.Matches, `(?ms).*"tokenUUIDs":\["`+strings.Split(arvadostest.ActiveTokenV2, "/")[1]+`"\].*`)
337 }
338
339 func (s *HandlerSuite) TestCreateAPIToken(c *check.C) {
340         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
341         auth, err := s.handler.createAPItoken(req, arvadostest.ActiveUserUUID, nil)
342         c.Assert(err, check.IsNil)
343         c.Check(auth.Scopes, check.DeepEquals, []string{"all"})
344
345         user, ok, err := s.handler.validateAPItoken(req, auth.TokenV2())
346         c.Assert(err, check.IsNil)
347         c.Check(ok, check.Equals, true)
348         c.Check(user.Authorization.UUID, check.Equals, auth.UUID)
349         c.Check(user.Authorization.APIToken, check.Equals, auth.APIToken)
350         c.Check(user.Authorization.Scopes, check.DeepEquals, []string{"all"})
351         c.Check(user.UUID, check.Equals, arvadostest.ActiveUserUUID)
352         c.Check(user.Authorization.TokenV2(), check.Equals, auth.TokenV2())
353 }
354
355 func (s *HandlerSuite) CheckObjectType(c *check.C, url string, token string, skippedFields map[string]bool) {
356         var proxied, direct map[string]interface{}
357         var err error
358
359         // Get collection from controller
360         req := httptest.NewRequest("GET", url, nil)
361         req.Header.Set("Authorization", "Bearer "+token)
362         resp := httptest.NewRecorder()
363         s.handler.ServeHTTP(resp, req)
364         c.Assert(resp.Code, check.Equals, http.StatusOK,
365                 check.Commentf("Wasn't able to get data from the controller at %q: %q", url, resp.Body.String()))
366         err = json.Unmarshal(resp.Body.Bytes(), &proxied)
367         c.Check(err, check.Equals, nil)
368
369         // Get collection directly from RailsAPI
370         client := &http.Client{
371                 Transport: &http.Transport{
372                         TLSClientConfig: &tls.Config{InsecureSkipVerify: true},
373                 },
374         }
375         resp2, err := client.Get(s.cluster.Services.RailsAPI.ExternalURL.String() + url + "/?api_token=" + token)
376         c.Check(err, check.Equals, nil)
377         c.Assert(resp2.StatusCode, check.Equals, http.StatusOK,
378                 check.Commentf("Wasn't able to get data from the RailsAPI at %q", url))
379         defer resp2.Body.Close()
380         db, err := ioutil.ReadAll(resp2.Body)
381         c.Check(err, check.Equals, nil)
382         err = json.Unmarshal(db, &direct)
383         c.Check(err, check.Equals, nil)
384
385         // Check that all RailsAPI provided keys exist on the controller response.
386         for k := range direct {
387                 if _, ok := skippedFields[k]; ok {
388                         continue
389                 } else if val, ok := proxied[k]; !ok {
390                         c.Errorf("%s's key %q missing on controller's response.", direct["kind"], k)
391                 } else if direct["kind"] == "arvados#collection" && k == "manifest_text" {
392                         // Tokens differ from request to request
393                         c.Check(strings.Split(val.(string), "+A")[0], check.Equals, strings.Split(direct[k].(string), "+A")[0])
394                 } else {
395                         c.Check(val, check.DeepEquals, direct[k],
396                                 check.Commentf("RailsAPI %s key %q's value %q differs from controller's %q.", direct["kind"], k, direct[k], val))
397                 }
398         }
399 }
400
401 func (s *HandlerSuite) TestGetObjects(c *check.C) {
402         // Get the 1st keep service's uuid from the running test server.
403         req := httptest.NewRequest("GET", "/arvados/v1/keep_services/", nil)
404         req.Header.Set("Authorization", "Bearer "+arvadostest.AdminToken)
405         resp := httptest.NewRecorder()
406         s.handler.ServeHTTP(resp, req)
407         c.Assert(resp.Code, check.Equals, http.StatusOK)
408         var ksList arvados.KeepServiceList
409         json.Unmarshal(resp.Body.Bytes(), &ksList)
410         c.Assert(len(ksList.Items), check.Not(check.Equals), 0)
411         ksUUID := ksList.Items[0].UUID
412         // Create a new token for the test user so that we're not comparing
413         // the ones from the fixtures.
414         req = httptest.NewRequest("POST", "/arvados/v1/api_client_authorizations",
415                 strings.NewReader(`{
416                         "api_client_authorization": {
417                                 "owner_uuid": "`+arvadostest.AdminUserUUID+`",
418                                 "created_by_ip_address": "::1",
419                                 "last_used_by_ip_address": "::1",
420                                 "default_owner_uuid": "`+arvadostest.AdminUserUUID+`"
421                         }
422                 }`))
423         req.Header.Set("Authorization", "Bearer "+arvadostest.SystemRootToken)
424         req.Header.Set("Content-type", "application/json")
425         resp = httptest.NewRecorder()
426         s.handler.ServeHTTP(resp, req)
427         c.Assert(resp.Code, check.Equals, http.StatusOK,
428                 check.Commentf("%s", resp.Body.String()))
429         var auth arvados.APIClientAuthorization
430         json.Unmarshal(resp.Body.Bytes(), &auth)
431         c.Assert(auth.UUID, check.Not(check.Equals), "")
432
433         testCases := map[string]map[string]bool{
434                 "api_clients/" + arvadostest.TrustedWorkbenchAPIClientUUID:     nil,
435                 "api_client_authorizations/" + auth.UUID:                       {"href": true, "modified_by_client_uuid": true, "modified_by_user_uuid": true},
436                 "authorized_keys/" + arvadostest.AdminAuthorizedKeysUUID:       nil,
437                 "collections/" + arvadostest.CollectionWithUniqueWordsUUID:     {"href": true},
438                 "containers/" + arvadostest.RunningContainerUUID:               nil,
439                 "container_requests/" + arvadostest.QueuedContainerRequestUUID: nil,
440                 "groups/" + arvadostest.AProjectUUID:                           nil,
441                 "keep_services/" + ksUUID:                                      nil,
442                 "links/" + arvadostest.ActiveUserCanReadAllUsersLinkUUID:       nil,
443                 "logs/" + arvadostest.CrunchstatForRunningJobLogUUID:           nil,
444                 "nodes/" + arvadostest.IdleNodeUUID:                            nil,
445                 "repositories/" + arvadostest.ArvadosRepoUUID:                  nil,
446                 "users/" + arvadostest.ActiveUserUUID:                          {"href": true},
447                 "virtual_machines/" + arvadostest.TestVMUUID:                   nil,
448                 "workflows/" + arvadostest.WorkflowWithDefinitionYAMLUUID:      nil,
449         }
450         for url, skippedFields := range testCases {
451                 c.Logf("Testing %q", url)
452                 s.CheckObjectType(c, "/arvados/v1/"+url, auth.TokenV2(), skippedFields)
453         }
454 }
455
456 func (s *HandlerSuite) TestRedactRailsAPIHostFromErrors(c *check.C) {
457         req := httptest.NewRequest("GET", "https://0.0.0.0:1/arvados/v1/collections/zzzzz-4zz18-abcdefghijklmno", nil)
458         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
459         resp := httptest.NewRecorder()
460         s.handler.ServeHTTP(resp, req)
461         c.Check(resp.Code, check.Equals, http.StatusNotFound)
462         var jresp struct {
463                 Errors []string
464         }
465         c.Log(resp.Body.String())
466         c.Assert(json.NewDecoder(resp.Body).Decode(&jresp), check.IsNil)
467         c.Assert(jresp.Errors, check.HasLen, 1)
468         c.Check(jresp.Errors[0], check.Matches, `.*//railsapi\.internal/arvados/v1/collections/.*: 404 Not Found.*`)
469         c.Check(jresp.Errors[0], check.Not(check.Matches), `(?ms).*127.0.0.1.*`)
470 }
471
472 func (s *HandlerSuite) TestTrashSweep(c *check.C) {
473         s.cluster.SystemRootToken = arvadostest.SystemRootToken
474         s.cluster.Collections.TrashSweepInterval = arvados.Duration(time.Second / 10)
475         s.handler.CheckHealth()
476         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
477         coll, err := s.handler.federation.CollectionCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{"name": "test trash sweep"}, EnsureUniqueName: true})
478         c.Assert(err, check.IsNil)
479         defer s.handler.federation.CollectionDelete(ctx, arvados.DeleteOptions{UUID: coll.UUID})
480         db, err := s.handler.dbConnector.GetDB(s.ctx)
481         c.Assert(err, check.IsNil)
482         _, err = db.ExecContext(s.ctx, `update collections set trash_at = $1, delete_at = $2 where uuid = $3`, time.Now().UTC().Add(time.Second/10), time.Now().UTC().Add(time.Hour), coll.UUID)
483         c.Assert(err, check.IsNil)
484         deadline := time.Now().Add(5 * time.Second)
485         for {
486                 if time.Now().After(deadline) {
487                         c.Log("timed out")
488                         c.FailNow()
489                 }
490                 updated, err := s.handler.federation.CollectionGet(ctx, arvados.GetOptions{UUID: coll.UUID, IncludeTrash: true})
491                 c.Assert(err, check.IsNil)
492                 if updated.IsTrashed {
493                         break
494                 }
495                 time.Sleep(time.Second / 10)
496         }
497 }
498
499 func (s *HandlerSuite) TestContainerLogSweep(c *check.C) {
500         s.cluster.SystemRootToken = arvadostest.SystemRootToken
501         s.cluster.Containers.Logging.SweepInterval = arvados.Duration(time.Second / 10)
502         s.handler.CheckHealth()
503         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
504         logentry, err := s.handler.federation.LogCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{
505                 "object_uuid": arvadostest.CompletedContainerUUID,
506                 "event_type":  "stderr",
507                 "properties": map[string]interface{}{
508                         "text": "test trash sweep\n",
509                 },
510         }})
511         c.Assert(err, check.IsNil)
512         defer s.handler.federation.LogDelete(ctx, arvados.DeleteOptions{UUID: logentry.UUID})
513         deadline := time.Now().Add(5 * time.Second)
514         for {
515                 if time.Now().After(deadline) {
516                         c.Log("timed out")
517                         c.FailNow()
518                 }
519                 logentries, err := s.handler.federation.LogList(ctx, arvados.ListOptions{Filters: []arvados.Filter{{"uuid", "=", logentry.UUID}}, Limit: -1})
520                 c.Assert(err, check.IsNil)
521                 if len(logentries.Items) == 0 {
522                         break
523                 }
524                 time.Sleep(time.Second / 10)
525         }
526 }
527
528 func (s *HandlerSuite) TestLogActivity(c *check.C) {
529         s.cluster.SystemRootToken = arvadostest.SystemRootToken
530         s.cluster.Users.ActivityLoggingPeriod = arvados.Duration(24 * time.Hour)
531         s.handler.CheckHealth()
532
533         testServer := newServerFromIntegrationTestEnv(c)
534         testServer.Server.Handler = httpserver.AddRequestIDs(httpserver.LogRequests(s.handler))
535         c.Assert(testServer.Start(), check.IsNil)
536         defer testServer.Close()
537
538         u, _ := url.Parse("http://" + testServer.Addr)
539         client := rpc.NewConn(s.cluster.ClusterID, u, true, rpc.PassthroughTokenProvider)
540
541         starttime := time.Now()
542         for i := 0; i < 4; i++ {
543                 for _, token := range []string{
544                         arvadostest.ActiveTokenV2,
545                         arvadostest.ActiveToken,
546                         arvadostest.SpectatorToken,
547                 } {
548                         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{token}})
549                         _, err := client.CollectionList(ctx, arvados.ListOptions{})
550                         c.Assert(err, check.IsNil)
551                 }
552         }
553         db, err := s.handler.dbConnector.GetDB(s.ctx)
554         c.Assert(err, check.IsNil)
555         for _, userUUID := range []string{arvadostest.ActiveUserUUID, arvadostest.SpectatorUserUUID} {
556                 var rows int
557                 err = db.QueryRowContext(s.ctx, `select count(uuid) from logs where object_uuid = $1 and event_at > $2`, arvadostest.ActiveUserUUID, starttime.UTC()).Scan(&rows)
558                 c.Assert(err, check.IsNil)
559                 c.Check(rows, check.Equals, 1, check.Commentf("expect 1 row for user uuid %s", userUUID))
560         }
561 }