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         "sync"
  20         "testing"
  21         "time"
  22
  23         "git.arvados.org/arvados.git/lib/controller/rpc"
  24         "git.arvados.org/arvados.git/sdk/go/arvados"
  25         "git.arvados.org/arvados.git/sdk/go/arvadostest"
  26         "git.arvados.org/arvados.git/sdk/go/auth"
  27         "git.arvados.org/arvados.git/sdk/go/ctxlog"
  28         "git.arvados.org/arvados.git/sdk/go/httpserver"
  29         "github.com/prometheus/client_golang/prometheus"
  30         check "gopkg.in/check.v1"
  31 )
  32
  33 // Gocheck boilerplate
  34 func Test(t *testing.T) {
  35         check.TestingT(t)
  36 }
  37
  38 var _ = check.Suite(&HandlerSuite{})
  39
  40 type HandlerSuite struct {
  41         cluster  *arvados.Cluster
  42         handler  *Handler
  43         railsSpy *arvadostest.Proxy
  44         logbuf   *bytes.Buffer
  45         ctx      context.Context
  46         cancel   context.CancelFunc
  47 }
  48
  49 func (s *HandlerSuite) SetUpTest(c *check.C) {
  50         s.logbuf = &bytes.Buffer{}
  51         s.ctx, s.cancel = context.WithCancel(context.Background())
  52         s.ctx = ctxlog.Context(s.ctx, ctxlog.New(io.MultiWriter(os.Stderr, s.logbuf), "json", "debug"))
  53         s.cluster = &arvados.Cluster{
  54                 ClusterID:  "zzzzz",
  55                 PostgreSQL: integrationTestCluster().PostgreSQL,
  56         }
  57         s.cluster.API.RequestTimeout = arvados.Duration(5 * time.Minute)
  58         s.cluster.TLS.Insecure = true
  59         arvadostest.SetServiceURL(&s.cluster.Services.RailsAPI, "https://"+os.Getenv("ARVADOS_TEST_API_HOST"))
  60         s.railsSpy = arvadostest.NewProxy(c, s.cluster.Services.RailsAPI)
  61         arvadostest.SetServiceURL(&s.cluster.Services.RailsAPI, s.railsSpy.URL.String())
  62         arvadostest.SetServiceURL(&s.cluster.Services.Controller, "http://localhost:/")
  63         s.handler = newHandler(s.ctx, s.cluster, "", prometheus.NewRegistry()).(*Handler)
  64 }
  65
  66 func (s *HandlerSuite) TearDownTest(c *check.C) {
  67         s.cancel()
  68 }
  69
  70 func (s *HandlerSuite) TestConfigExport(c *check.C) {
  71         s.cluster.ManagementToken = "secret"
  72         s.cluster.SystemRootToken = "secret"
  73         s.cluster.Collections.BlobSigning = true
  74         s.cluster.Collections.BlobSigningTTL = arvados.Duration(23 * time.Second)
  75         for _, method := range []string{"GET", "OPTIONS"} {
  76                 req := httptest.NewRequest(method, "/arvados/v1/config", nil)
  77                 resp := httptest.NewRecorder()
  78                 s.handler.ServeHTTP(resp, req)
  79                 c.Log(resp.Body.String())
  80                 if !c.Check(resp.Code, check.Equals, http.StatusOK) {
  81                         continue
  82                 }
  83                 c.Check(resp.Header().Get("Access-Control-Allow-Origin"), check.Equals, `*`)
  84                 c.Check(resp.Header().Get("Access-Control-Allow-Methods"), check.Matches, `.*\bGET\b.*`)
  85                 c.Check(resp.Header().Get("Access-Control-Allow-Headers"), check.Matches, `.+`)
  86                 if method == "OPTIONS" {
  87                         c.Check(resp.Body.String(), check.HasLen, 0)
  88                         continue
  89                 }
  90                 var cluster arvados.Cluster
  91                 err := json.Unmarshal(resp.Body.Bytes(), &cluster)
  92                 c.Check(err, check.IsNil)
  93                 c.Check(cluster.ManagementToken, check.Equals, "")
  94                 c.Check(cluster.SystemRootToken, check.Equals, "")
  95                 c.Check(cluster.Collections.BlobSigning, check.Equals, true)
  96                 c.Check(cluster.Collections.BlobSigningTTL, check.Equals, arvados.Duration(23*time.Second))
  97         }
  98 }
  99
 100 func (s *HandlerSuite) TestDiscoveryDocCache(c *check.C) {
 101         countRailsReqs := func() int {
 102                 n := 0
 103                 for _, req := range s.railsSpy.RequestDumps {
 104                         if bytes.Contains(req, []byte("/discovery/v1/apis/arvados/v1/rest")) {
 105                                 n++
 106                         }
 107                 }
 108                 return n
 109         }
 110         getDD := func() int {
 111                 req := httptest.NewRequest(http.MethodGet, "/discovery/v1/apis/arvados/v1/rest", nil)
 112                 resp := httptest.NewRecorder()
 113                 s.handler.ServeHTTP(resp, req)
 114                 if resp.Code == http.StatusOK {
 115                         var dd arvados.DiscoveryDocument
 116                         err := json.Unmarshal(resp.Body.Bytes(), &dd)
 117                         c.Check(err, check.IsNil)
 118                         c.Check(dd.Schemas["Collection"].UUIDPrefix, check.Equals, "4zz18")
 119                 }
 120                 return resp.Code
 121         }
 122         getDDConcurrently := func(n int, expectCode int, checkArgs ...interface{}) *sync.WaitGroup {
 123                 var wg sync.WaitGroup
 124                 for i := 0; i < n; i++ {
 125                         wg.Add(1)
 126                         go func() {
 127                                 defer wg.Done()
 128                                 c.Check(getDD(), check.Equals, append([]interface{}{expectCode}, checkArgs...)...)
 129                         }()
 130                 }
 131                 return &wg
 132         }
 133         clearCache := func() {
 134                 for path := range s.handler.cache {
 135                         s.handler.cache[path] = &cacheEnt{}
 136                 }
 137         }
 138         expireCache := func() {
 139                 for _, ent := range s.handler.cache {
 140                         ent.refreshAfter = time.Now()
 141                 }
 142         }
 143         waitPendingUpdates := func() {
 144                 for _, ent := range s.handler.cache {
 145                         ent.refreshLock.Lock()
 146                         defer ent.refreshLock.Unlock()
 147                         ent.mtx.Lock()
 148                         defer ent.mtx.Unlock()
 149                 }
 150         }
 151
 152         // Easy path: first req fetches, subsequent reqs use cache.
 153         c.Check(countRailsReqs(), check.Equals, 0)
 154         c.Check(getDD(), check.Equals, http.StatusOK)
 155         c.Check(countRailsReqs(), check.Equals, 1)
 156         c.Check(getDD(), check.Equals, http.StatusOK)
 157         c.Check(countRailsReqs(), check.Equals, 1)
 158         c.Check(getDD(), check.Equals, http.StatusOK)
 159         c.Check(countRailsReqs(), check.Equals, 1)
 160
 161         // To guarantee we have concurrent requests, we set up
 162         // railsSpy to hold up the Handler's outgoing requests until
 163         // we send to (or close) holdReqs.
 164         holdReqs := make(chan struct{})
 165         s.railsSpy.Director = func(*http.Request) {
 166                 <-holdReqs
 167         }
 168
 169         // Race at startup: first req fetches, other concurrent reqs
 170         // wait for the initial fetch to complete, then all return.
 171         clearCache()
 172         reqsBefore := countRailsReqs()
 173         wg := getDDConcurrently(5, http.StatusOK, check.Commentf("race at startup"))
 174         close(holdReqs)
 175         wg.Wait()
 176         c.Check(countRailsReqs(), check.Equals, reqsBefore+1)
 177
 178         // Race after expiry: concurrent reqs return the cached data
 179         // but initiate a new fetch in the background.
 180         expireCache()
 181         holdReqs = make(chan struct{})
 182         wg = getDDConcurrently(5, http.StatusOK, check.Commentf("race after expiry"))
 183         reqsBefore = countRailsReqs()
 184         close(holdReqs)
 185         wg.Wait()
 186         for deadline := time.Now().Add(time.Second); time.Now().Before(deadline) && countRailsReqs() < reqsBefore+1; {
 187                 time.Sleep(time.Second / 100)
 188         }
 189         c.Check(countRailsReqs(), check.Equals, reqsBefore+1)
 190
 191         // Configure railsSpy to return an error when wantError==true.
 192         var wantError bool
 193         s.railsSpy.Director = func(req *http.Request) {
 194                 if wantError {
 195                         req.Method = "MAKE-COFFEE"
 196                 }
 197         }
 198
 199         // Error at startup (empty cache) => caller gets error, and we
 200         // make an upstream attempt for each incoming request because
 201         // we have nothing better to return
 202         clearCache()
 203         wantError = true
 204         reqsBefore = countRailsReqs()
 205         holdReqs = make(chan struct{})
 206         wg = getDDConcurrently(5, http.StatusBadGateway, check.Commentf("error at startup"))
 207         close(holdReqs)
 208         wg.Wait()
 209         c.Check(countRailsReqs(), check.Equals, reqsBefore+5)
 210
 211         // Error condition clears => caller gets OK, cache is warmed
 212         // up
 213         wantError = false
 214         reqsBefore = countRailsReqs()
 215         getDDConcurrently(5, http.StatusOK, check.Commentf("success after errors at startup")).Wait()
 216         c.Check(countRailsReqs(), check.Equals, reqsBefore+1)
 217
 218         // Error with warm cache => caller gets OK (with no attempt to
 219         // re-fetch)
 220         wantError = true
 221         reqsBefore = countRailsReqs()
 222         getDDConcurrently(5, http.StatusOK, check.Commentf("error with warm cache")).Wait()
 223         c.Check(countRailsReqs(), check.Equals, reqsBefore)
 224         expireCache()
 225
 226         // Error with expired cache => caller gets OK with stale data
 227         // while the re-fetch is attempted in the background
 228         reqsBefore = countRailsReqs()
 229         holdReqs = make(chan struct{})
 230         getDDConcurrently(5, http.StatusOK, check.Commentf("error with expired cache")).Wait()
 231         close(holdReqs)
 232         // Only one attempt to re-fetch (holdReqs ensured the first
 233         // update took long enough for the last incoming request to
 234         // arrive)
 235         c.Check(countRailsReqs(), check.Equals, reqsBefore+1)
 236
 237         waitPendingUpdates()
 238         expireCache()
 239         wantError = false
 240         reqsBefore = countRailsReqs()
 241         holdReqs = make(chan struct{})
 242         getDDConcurrently(5, http.StatusOK, check.Commentf("refresh cache after error condition clears")).Wait()
 243         close(holdReqs)
 244         c.Check(countRailsReqs(), check.Equals, reqsBefore+1)
 245 }
 246
 247 func (s *HandlerSuite) TestVocabularyExport(c *check.C) {
 248         voc := `{
 249                 "strict_tags": false,
 250                 "tags": {
 251                         "IDTAGIMPORTANCE": {
 252                                 "strict": false,
 253                                 "labels": [{"label": "Importance"}],
 254                                 "values": {
 255                                         "HIGH": {
 256                                                 "labels": [{"label": "High"}]
 257                                         },
 258                                         "LOW": {
 259                                                 "labels": [{"label": "Low"}]
 260                                         }
 261                                 }
 262                         }
 263                 }
 264         }`
 265         f, err := os.CreateTemp("", "test-vocabulary-*.json")
 266         c.Assert(err, check.IsNil)
 267         defer os.Remove(f.Name())
 268         _, err = f.WriteString(voc)
 269         c.Assert(err, check.IsNil)
 270         f.Close()
 271         s.cluster.API.VocabularyPath = f.Name()
 272         for _, method := range []string{"GET", "OPTIONS"} {
 273                 c.Log(c.TestName()+" ", method)
 274                 req := httptest.NewRequest(method, "/arvados/v1/vocabulary", nil)
 275                 resp := httptest.NewRecorder()
 276                 s.handler.ServeHTTP(resp, req)
 277                 c.Log(resp.Body.String())
 278                 if !c.Check(resp.Code, check.Equals, http.StatusOK) {
 279                         continue
 280                 }
 281                 c.Check(resp.Header().Get("Access-Control-Allow-Origin"), check.Equals, `*`)
 282                 c.Check(resp.Header().Get("Access-Control-Allow-Methods"), check.Matches, `.*\bGET\b.*`)
 283                 c.Check(resp.Header().Get("Access-Control-Allow-Headers"), check.Matches, `.+`)
 284                 if method == "OPTIONS" {
 285                         c.Check(resp.Body.String(), check.HasLen, 0)
 286                         continue
 287                 }
 288                 var expectedVoc, receivedVoc *arvados.Vocabulary
 289                 err := json.Unmarshal([]byte(voc), &expectedVoc)
 290                 c.Check(err, check.IsNil)
 291                 err = json.Unmarshal(resp.Body.Bytes(), &receivedVoc)
 292                 c.Check(err, check.IsNil)
 293                 c.Check(receivedVoc, check.DeepEquals, expectedVoc)
 294         }
 295 }
 296
 297 func (s *HandlerSuite) TestVocabularyFailedCheckStatus(c *check.C) {
 298         voc := `{
 299                 "strict_tags": false,
 300                 "tags": {
 301                         "IDTAGIMPORTANCE": {
 302                                 "strict": true,
 303                                 "labels": [{"label": "Importance"}],
 304                                 "values": {
 305                                         "HIGH": {
 306                                                 "labels": [{"label": "High"}]
 307                                         },
 308                                         "LOW": {
 309                                                 "labels": [{"label": "Low"}]
 310                                         }
 311                                 }
 312                         }
 313                 }
 314         }`
 315         f, err := os.CreateTemp("", "test-vocabulary-*.json")
 316         c.Assert(err, check.IsNil)
 317         defer os.Remove(f.Name())
 318         _, err = f.WriteString(voc)
 319         c.Assert(err, check.IsNil)
 320         f.Close()
 321         s.cluster.API.VocabularyPath = f.Name()
 322
 323         req := httptest.NewRequest("POST", "/arvados/v1/collections",
 324                 strings.NewReader(`{
 325                         "collection": {
 326                                 "properties": {
 327                                         "IDTAGIMPORTANCE": "Critical"
 328                                 }
 329                         }
 330                 }`))
 331         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 332         req.Header.Set("Content-type", "application/json")
 333
 334         resp := httptest.NewRecorder()
 335         s.handler.ServeHTTP(resp, req)
 336         c.Log(resp.Body.String())
 337         c.Assert(resp.Code, check.Equals, http.StatusBadRequest)
 338         var jresp httpserver.ErrorResponse
 339         err = json.Unmarshal(resp.Body.Bytes(), &jresp)
 340         c.Check(err, check.IsNil)
 341         c.Assert(len(jresp.Errors), check.Equals, 1)
 342         c.Check(jresp.Errors[0], check.Matches, `.*tag value.*is not valid for key.*`)
 343 }
 344
 345 func (s *HandlerSuite) TestProxyDiscoveryDoc(c *check.C) {
 346         req := httptest.NewRequest("GET", "/discovery/v1/apis/arvados/v1/rest", nil)
 347         resp := httptest.NewRecorder()
 348         s.handler.ServeHTTP(resp, req)
 349         c.Check(resp.Code, check.Equals, http.StatusOK)
 350         var dd arvados.DiscoveryDocument
 351         err := json.Unmarshal(resp.Body.Bytes(), &dd)
 352         c.Check(err, check.IsNil)
 353         c.Check(dd.BlobSignatureTTL, check.Not(check.Equals), int64(0))
 354         c.Check(dd.BlobSignatureTTL > 0, check.Equals, true)
 355         c.Check(len(dd.Resources), check.Not(check.Equals), 0)
 356         c.Check(len(dd.Schemas), check.Not(check.Equals), 0)
 357 }
 358
 359 // Handler should give up and exit early if request context is
 360 // cancelled due to client hangup, httpserver.HandlerWithDeadline,
 361 // etc.
 362 func (s *HandlerSuite) TestRequestCancel(c *check.C) {
 363         ctx, cancel := context.WithCancel(context.Background())
 364         req := httptest.NewRequest("GET", "/static/login_failure", nil).WithContext(ctx)
 365         resp := httptest.NewRecorder()
 366         cancel()
 367         s.handler.ServeHTTP(resp, req)
 368         c.Check(resp.Code, check.Equals, http.StatusBadGateway)
 369         var jresp httpserver.ErrorResponse
 370         err := json.Unmarshal(resp.Body.Bytes(), &jresp)
 371         c.Check(err, check.IsNil)
 372         c.Assert(len(jresp.Errors), check.Equals, 1)
 373         c.Check(jresp.Errors[0], check.Matches, `.*context canceled`)
 374 }
 375
 376 func (s *HandlerSuite) TestProxyWithoutToken(c *check.C) {
 377         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 378         resp := httptest.NewRecorder()
 379         s.handler.ServeHTTP(resp, req)
 380         c.Check(resp.Code, check.Equals, http.StatusUnauthorized)
 381         jresp := map[string]interface{}{}
 382         err := json.Unmarshal(resp.Body.Bytes(), &jresp)
 383         c.Check(err, check.IsNil)
 384         c.Check(jresp["errors"], check.FitsTypeOf, []interface{}{})
 385 }
 386
 387 func (s *HandlerSuite) TestProxyWithToken(c *check.C) {
 388         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 389         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 390         resp := httptest.NewRecorder()
 391         s.handler.ServeHTTP(resp, req)
 392         c.Check(resp.Code, check.Equals, http.StatusOK)
 393         var u arvados.User
 394         err := json.Unmarshal(resp.Body.Bytes(), &u)
 395         c.Check(err, check.IsNil)
 396         c.Check(u.UUID, check.Equals, arvadostest.ActiveUserUUID)
 397 }
 398
 399 func (s *HandlerSuite) TestProxyWithTokenInRequestBody(c *check.C) {
 400         req := httptest.NewRequest("POST", "/arvados/v1/users/current", strings.NewReader(url.Values{
 401                 "_method":   {"GET"},
 402                 "api_token": {arvadostest.ActiveToken},
 403         }.Encode()))
 404         req.Header.Set("Content-type", "application/x-www-form-urlencoded")
 405         resp := httptest.NewRecorder()
 406         s.handler.ServeHTTP(resp, req)
 407         c.Check(resp.Code, check.Equals, http.StatusOK)
 408         var u arvados.User
 409         err := json.Unmarshal(resp.Body.Bytes(), &u)
 410         c.Check(err, check.IsNil)
 411         c.Check(u.UUID, check.Equals, arvadostest.ActiveUserUUID)
 412 }
 413
 414 func (s *HandlerSuite) TestProxyNotFound(c *check.C) {
 415         req := httptest.NewRequest("GET", "/arvados/v1/xyzzy", nil)
 416         resp := httptest.NewRecorder()
 417         s.handler.ServeHTTP(resp, req)
 418         c.Check(resp.Code, check.Equals, http.StatusNotFound)
 419         jresp := map[string]interface{}{}
 420         err := json.Unmarshal(resp.Body.Bytes(), &jresp)
 421         c.Check(err, check.IsNil)
 422         c.Check(jresp["errors"], check.FitsTypeOf, []interface{}{})
 423 }
 424
 425 func (s *HandlerSuite) TestLogoutGoogle(c *check.C) {
 426         s.cluster.Services.Workbench2.ExternalURL = arvados.URL{Scheme: "https", Host: "wb2.example", Path: "/"}
 427         s.cluster.Login.Google.Enable = true
 428         s.cluster.Login.Google.ClientID = "test"
 429         req := httptest.NewRequest("GET", "https://0.0.0.0:1/logout?return_to=https://wb2.example/", nil)
 430         resp := httptest.NewRecorder()
 431         s.handler.ServeHTTP(resp, req)
 432         if !c.Check(resp.Code, check.Equals, http.StatusFound) {
 433                 c.Log(resp.Body.String())
 434         }
 435         c.Check(resp.Header().Get("Location"), check.Equals, "https://wb2.example/")
 436 }
 437
 438 func (s *HandlerSuite) TestValidateV1APIToken(c *check.C) {
 439         c.Assert(s.handler.CheckHealth(), check.IsNil)
 440         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 441         user, ok, err := s.handler.validateAPItoken(req, arvadostest.ActiveToken)
 442         c.Assert(err, check.IsNil)
 443         c.Check(ok, check.Equals, true)
 444         c.Check(user.Authorization.UUID, check.Equals, arvadostest.ActiveTokenUUID)
 445         c.Check(user.Authorization.APIToken, check.Equals, arvadostest.ActiveToken)
 446         c.Check(user.Authorization.Scopes, check.DeepEquals, []string{"all"})
 447         c.Check(user.UUID, check.Equals, arvadostest.ActiveUserUUID)
 448 }
 449
 450 func (s *HandlerSuite) TestValidateV2APIToken(c *check.C) {
 451         c.Assert(s.handler.CheckHealth(), check.IsNil)
 452         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 453         user, ok, err := s.handler.validateAPItoken(req, arvadostest.ActiveTokenV2)
 454         c.Assert(err, check.IsNil)
 455         c.Check(ok, check.Equals, true)
 456         c.Check(user.Authorization.UUID, check.Equals, arvadostest.ActiveTokenUUID)
 457         c.Check(user.Authorization.APIToken, check.Equals, arvadostest.ActiveToken)
 458         c.Check(user.Authorization.Scopes, check.DeepEquals, []string{"all"})
 459         c.Check(user.UUID, check.Equals, arvadostest.ActiveUserUUID)
 460         c.Check(user.Authorization.TokenV2(), check.Equals, arvadostest.ActiveTokenV2)
 461 }
 462
 463 func (s *HandlerSuite) TestValidateRemoteToken(c *check.C) {
 464         saltedToken, err := auth.SaltToken(arvadostest.ActiveTokenV2, "abcde")
 465         c.Assert(err, check.IsNil)
 466         for _, trial := range []struct {
 467                 code  int
 468                 token string
 469         }{
 470                 {http.StatusOK, saltedToken},
 471                 {http.StatusUnauthorized, "bogus"},
 472         } {
 473                 req := httptest.NewRequest("GET", "https://0.0.0.0:1/arvados/v1/users/current?remote=abcde", nil)
 474                 req.Header.Set("Authorization", "Bearer "+trial.token)
 475                 resp := httptest.NewRecorder()
 476                 s.handler.ServeHTTP(resp, req)
 477                 if !c.Check(resp.Code, check.Equals, trial.code) {
 478                         c.Logf("HTTP %d: %s", resp.Code, resp.Body.String())
 479                 }
 480         }
 481 }
 482
 483 func (s *HandlerSuite) TestLogTokenUUID(c *check.C) {
 484         req := httptest.NewRequest("GET", "https://0.0.0.0/arvados/v1/users/current", nil)
 485         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveTokenV2)
 486         req = req.WithContext(s.ctx)
 487         resp := httptest.NewRecorder()
 488         httpserver.LogRequests(s.handler).ServeHTTP(resp, req)
 489         c.Check(resp.Code, check.Equals, http.StatusOK)
 490         c.Check(s.logbuf.String(), check.Matches, `(?ms).*"tokenUUIDs":\["`+strings.Split(arvadostest.ActiveTokenV2, "/")[1]+`"\].*`)
 491 }
 492
 493 func (s *HandlerSuite) TestCreateAPIToken(c *check.C) {
 494         c.Assert(s.handler.CheckHealth(), check.IsNil)
 495         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 496         auth, err := s.handler.createAPItoken(req, arvadostest.ActiveUserUUID, nil)
 497         c.Assert(err, check.IsNil)
 498         c.Check(auth.Scopes, check.DeepEquals, []string{"all"})
 499
 500         user, ok, err := s.handler.validateAPItoken(req, auth.TokenV2())
 501         c.Assert(err, check.IsNil)
 502         c.Check(ok, check.Equals, true)
 503         c.Check(user.Authorization.UUID, check.Equals, auth.UUID)
 504         c.Check(user.Authorization.APIToken, check.Equals, auth.APIToken)
 505         c.Check(user.Authorization.Scopes, check.DeepEquals, []string{"all"})
 506         c.Check(user.UUID, check.Equals, arvadostest.ActiveUserUUID)
 507         c.Check(user.Authorization.TokenV2(), check.Equals, auth.TokenV2())
 508 }
 509
 510 func (s *HandlerSuite) CheckObjectType(c *check.C, url string, token string, skippedFields map[string]bool) {
 511         var proxied, direct map[string]interface{}
 512         var err error
 513
 514         // Get collection from controller
 515         req := httptest.NewRequest("GET", url, nil)
 516         req.Header.Set("Authorization", "Bearer "+token)
 517         resp := httptest.NewRecorder()
 518         s.handler.ServeHTTP(resp, req)
 519         c.Assert(resp.Code, check.Equals, http.StatusOK,
 520                 check.Commentf("Wasn't able to get data from the controller at %q: %q", url, resp.Body.String()))
 521         err = json.Unmarshal(resp.Body.Bytes(), &proxied)
 522         c.Check(err, check.Equals, nil)
 523
 524         // Get collection directly from RailsAPI
 525         client := &http.Client{
 526                 Transport: &http.Transport{
 527                         TLSClientConfig: &tls.Config{InsecureSkipVerify: true},
 528                 },
 529         }
 530         resp2, err := client.Get(s.cluster.Services.RailsAPI.ExternalURL.String() + url + "/?api_token=" + token)
 531         c.Check(err, check.Equals, nil)
 532         c.Assert(resp2.StatusCode, check.Equals, http.StatusOK,
 533                 check.Commentf("Wasn't able to get data from the RailsAPI at %q", url))
 534         defer resp2.Body.Close()
 535         db, err := ioutil.ReadAll(resp2.Body)
 536         c.Check(err, check.Equals, nil)
 537         err = json.Unmarshal(db, &direct)
 538         c.Check(err, check.Equals, nil)
 539
 540         // Check that all RailsAPI provided keys exist on the controller response.
 541         for k := range direct {
 542                 if _, ok := skippedFields[k]; ok {
 543                         continue
 544                 } else if val, ok := proxied[k]; !ok {
 545                         c.Errorf("%s's key %q missing on controller's response.", direct["kind"], k)
 546                 } else if direct["kind"] == "arvados#collection" && k == "manifest_text" {
 547                         // Tokens differ from request to request
 548                         c.Check(strings.Split(val.(string), "+A")[0], check.Equals, strings.Split(direct[k].(string), "+A")[0])
 549                 } else {
 550                         c.Check(val, check.DeepEquals, direct[k],
 551                                 check.Commentf("RailsAPI %s key %q's value %q differs from controller's %q.", direct["kind"], k, direct[k], val))
 552                 }
 553         }
 554 }
 555
 556 func (s *HandlerSuite) TestGetObjects(c *check.C) {
 557         // Get the 1st keep service's uuid from the running test server.
 558         req := httptest.NewRequest("GET", "/arvados/v1/keep_services/", nil)
 559         req.Header.Set("Authorization", "Bearer "+arvadostest.AdminToken)
 560         resp := httptest.NewRecorder()
 561         s.handler.ServeHTTP(resp, req)
 562         c.Assert(resp.Code, check.Equals, http.StatusOK)
 563         var ksList arvados.KeepServiceList
 564         json.Unmarshal(resp.Body.Bytes(), &ksList)
 565         c.Assert(len(ksList.Items), check.Not(check.Equals), 0)
 566         ksUUID := ksList.Items[0].UUID
 567         // Create a new token for the test user so that we're not comparing
 568         // the ones from the fixtures.
 569         req = httptest.NewRequest("POST", "/arvados/v1/api_client_authorizations",
 570                 strings.NewReader(`{
 571                         "api_client_authorization": {
 572                                 "owner_uuid": "`+arvadostest.AdminUserUUID+`",
 573                                 "created_by_ip_address": "::1",
 574                                 "last_used_by_ip_address": "::1",
 575                                 "default_owner_uuid": "`+arvadostest.AdminUserUUID+`"
 576                         }
 577                 }`))
 578         req.Header.Set("Authorization", "Bearer "+arvadostest.SystemRootToken)
 579         req.Header.Set("Content-type", "application/json")
 580         resp = httptest.NewRecorder()
 581         s.handler.ServeHTTP(resp, req)
 582         c.Assert(resp.Code, check.Equals, http.StatusOK,
 583                 check.Commentf("%s", resp.Body.String()))
 584         var auth arvados.APIClientAuthorization
 585         json.Unmarshal(resp.Body.Bytes(), &auth)
 586         c.Assert(auth.UUID, check.Not(check.Equals), "")
 587
 588         testCases := map[string]map[string]bool{
 589                 "api_clients/" + arvadostest.TrustedWorkbenchAPIClientUUID:     nil,
 590                 "api_client_authorizations/" + auth.UUID:                       {"href": true, "modified_by_client_uuid": true, "modified_by_user_uuid": true},
 591                 "authorized_keys/" + arvadostest.AdminAuthorizedKeysUUID:       nil,
 592                 "collections/" + arvadostest.CollectionWithUniqueWordsUUID:     {"href": true},
 593                 "containers/" + arvadostest.RunningContainerUUID:               nil,
 594                 "container_requests/" + arvadostest.QueuedContainerRequestUUID: nil,
 595                 "groups/" + arvadostest.AProjectUUID:                           nil,
 596                 "keep_services/" + ksUUID:                                      nil,
 597                 "links/" + arvadostest.ActiveUserCanReadAllUsersLinkUUID:       nil,
 598                 "logs/" + arvadostest.CrunchstatForRunningJobLogUUID:           nil,
 599                 "nodes/" + arvadostest.IdleNodeUUID:                            nil,
 600                 "repositories/" + arvadostest.ArvadosRepoUUID:                  nil,
 601                 "users/" + arvadostest.ActiveUserUUID:                          {"href": true},
 602                 "virtual_machines/" + arvadostest.TestVMUUID:                   nil,
 603                 "workflows/" + arvadostest.WorkflowWithDefinitionYAMLUUID:      nil,
 604         }
 605         for url, skippedFields := range testCases {
 606                 c.Logf("Testing %q", url)
 607                 s.CheckObjectType(c, "/arvados/v1/"+url, auth.TokenV2(), skippedFields)
 608         }
 609 }
 610
 611 func (s *HandlerSuite) TestRedactRailsAPIHostFromErrors(c *check.C) {
 612         req := httptest.NewRequest("GET", "https://0.0.0.0:1/arvados/v1/collections/zzzzz-4zz18-abcdefghijklmno", nil)
 613         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 614         resp := httptest.NewRecorder()
 615         s.handler.ServeHTTP(resp, req)
 616         c.Check(resp.Code, check.Equals, http.StatusNotFound)
 617         var jresp struct {
 618                 Errors []string
 619         }
 620         c.Log(resp.Body.String())
 621         c.Assert(json.NewDecoder(resp.Body).Decode(&jresp), check.IsNil)
 622         c.Assert(jresp.Errors, check.HasLen, 1)
 623         c.Check(jresp.Errors[0], check.Matches, `.*//railsapi\.internal/arvados/v1/collections/.*: 404 Not Found.*`)
 624         c.Check(jresp.Errors[0], check.Not(check.Matches), `(?ms).*127.0.0.1.*`)
 625 }
 626
 627 func (s *HandlerSuite) TestTrashSweep(c *check.C) {
 628         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 629         s.cluster.Collections.TrashSweepInterval = arvados.Duration(time.Second / 10)
 630         s.handler.CheckHealth()
 631         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
 632         coll, err := s.handler.federation.CollectionCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{"name": "test trash sweep"}, EnsureUniqueName: true})
 633         c.Assert(err, check.IsNil)
 634         defer s.handler.federation.CollectionDelete(ctx, arvados.DeleteOptions{UUID: coll.UUID})
 635         db, err := s.handler.dbConnector.GetDB(s.ctx)
 636         c.Assert(err, check.IsNil)
 637         _, 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)
 638         c.Assert(err, check.IsNil)
 639         deadline := time.Now().Add(5 * time.Second)
 640         for {
 641                 if time.Now().After(deadline) {
 642                         c.Log("timed out")
 643                         c.FailNow()
 644                 }
 645                 updated, err := s.handler.federation.CollectionGet(ctx, arvados.GetOptions{UUID: coll.UUID, IncludeTrash: true})
 646                 c.Assert(err, check.IsNil)
 647                 if updated.IsTrashed {
 648                         break
 649                 }
 650                 time.Sleep(time.Second / 10)
 651         }
 652 }
 653
 654 func (s *HandlerSuite) TestContainerLogSweep(c *check.C) {
 655         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 656         s.cluster.Containers.Logging.SweepInterval = arvados.Duration(time.Second / 10)
 657         s.handler.CheckHealth()
 658         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
 659         logentry, err := s.handler.federation.LogCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{
 660                 "object_uuid": arvadostest.CompletedContainerUUID,
 661                 "event_type":  "stderr",
 662                 "properties": map[string]interface{}{
 663                         "text": "test trash sweep\n",
 664                 },
 665         }})
 666         c.Assert(err, check.IsNil)
 667         defer s.handler.federation.LogDelete(ctx, arvados.DeleteOptions{UUID: logentry.UUID})
 668         deadline := time.Now().Add(5 * time.Second)
 669         for {
 670                 if time.Now().After(deadline) {
 671                         c.Log("timed out")
 672                         c.FailNow()
 673                 }
 674                 logentries, err := s.handler.federation.LogList(ctx, arvados.ListOptions{Filters: []arvados.Filter{{"uuid", "=", logentry.UUID}}, Limit: -1})
 675                 c.Assert(err, check.IsNil)
 676                 if len(logentries.Items) == 0 {
 677                         break
 678                 }
 679                 time.Sleep(time.Second / 10)
 680         }
 681 }
 682
 683 func (s *HandlerSuite) TestLogActivity(c *check.C) {
 684         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 685         s.cluster.Users.ActivityLoggingPeriod = arvados.Duration(24 * time.Hour)
 686         s.handler.CheckHealth()
 687
 688         testServer := newServerFromIntegrationTestEnv(c)
 689         testServer.Server.Handler = httpserver.AddRequestIDs(httpserver.LogRequests(s.handler))
 690         c.Assert(testServer.Start(), check.IsNil)
 691         defer testServer.Close()
 692
 693         u, _ := url.Parse("http://" + testServer.Addr)
 694         client := rpc.NewConn(s.cluster.ClusterID, u, true, rpc.PassthroughTokenProvider)
 695
 696         starttime := time.Now()
 697         for i := 0; i < 4; i++ {
 698                 for _, token := range []string{
 699                         arvadostest.ActiveTokenV2,
 700                         arvadostest.ActiveToken,
 701                         arvadostest.SpectatorToken,
 702                 } {
 703                         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{token}})
 704                         _, err := client.CollectionList(ctx, arvados.ListOptions{})
 705                         c.Assert(err, check.IsNil)
 706                 }
 707         }
 708         db, err := s.handler.dbConnector.GetDB(s.ctx)
 709         c.Assert(err, check.IsNil)
 710         for _, userUUID := range []string{arvadostest.ActiveUserUUID, arvadostest.SpectatorUserUUID} {
 711                 var rows int
 712                 err = db.QueryRowContext(s.ctx, `select count(uuid) from logs where object_uuid = $1 and event_at > $2`, arvadostest.ActiveUserUUID, starttime.UTC()).Scan(&rows)
 713                 c.Assert(err, check.IsNil)
 714                 c.Check(rows, check.Equals, 1, check.Commentf("expect 1 row for user uuid %s", userUUID))
 715         }
 716 }
 717
 718 func (s *HandlerSuite) TestLogLimiting(c *check.C) {
 719         s.handler.Cluster.API.MaxConcurrentRequests = 2
 720         s.handler.Cluster.API.LogCreateRequestFraction = 0.5
 721
 722         logreq := httptest.NewRequest("POST", "/arvados/v1/logs", strings.NewReader(`{
 723                         "log": {
 724                           "event_type": "test"
 725                         }
 726                 }`))
 727         logreq.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 728
 729         // Log create succeeds
 730         for i := 0; i < 2; i++ {
 731                 resp := httptest.NewRecorder()
 732                 s.handler.ServeHTTP(resp, logreq)
 733                 c.Check(resp.Code, check.Equals, http.StatusOK)
 734                 var lg arvados.Log
 735                 err := json.Unmarshal(resp.Body.Bytes(), &lg)
 736                 c.Check(err, check.IsNil)
 737                 c.Check(lg.UUID, check.Matches, "zzzzz-57u5n-.*")
 738         }
 739
 740         // Pretend there's a log create in flight
 741         s.handler.limitLogCreate <- struct{}{}
 742
 743         // Log create should be rejected now
 744         resp := httptest.NewRecorder()
 745         s.handler.ServeHTTP(resp, logreq)
 746         c.Check(resp.Code, check.Equals, http.StatusServiceUnavailable)
 747
 748         // Other requests still succeed
 749         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 750         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 751         resp = httptest.NewRecorder()
 752         s.handler.ServeHTTP(resp, req)
 753         c.Check(resp.Code, check.Equals, http.StatusOK)
 754         var u arvados.User
 755         err := json.Unmarshal(resp.Body.Bytes(), &u)
 756         c.Check(err, check.IsNil)
 757         c.Check(u.UUID, check.Equals, arvadostest.ActiveUserUUID)
 758
 759         // log create still fails
 760         resp = httptest.NewRecorder()
 761         s.handler.ServeHTTP(resp, logreq)
 762         c.Check(resp.Code, check.Equals, http.StatusServiceUnavailable)
 763
 764         // Pretend in-flight log is done
 765         <-s.handler.limitLogCreate
 766
 767         // log create succeeds again
 768         resp = httptest.NewRecorder()
 769         s.handler.ServeHTTP(resp, logreq)
 770         c.Check(resp.Code, check.Equals, http.StatusOK)
 771
 772 }