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