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