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