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                         }
 652                 }`))
 653         req.Header.Set("Authorization", "Bearer "+arvadostest.SystemRootToken)
 654         req.Header.Set("Content-type", "application/json")
 655         resp = httptest.NewRecorder()
 656         s.handler.ServeHTTP(resp, req)
 657         c.Assert(resp.Code, check.Equals, http.StatusOK,
 658                 check.Commentf("%s", resp.Body.String()))
 659         var auth arvados.APIClientAuthorization
 660         json.Unmarshal(resp.Body.Bytes(), &auth)
 661         c.Assert(auth.UUID, check.Not(check.Equals), "")
 662
 663         testCases := map[string]map[string]bool{
 664                 "api_client_authorizations/" + auth.UUID:                       {"href": true, "modified_by_client_uuid": true, "modified_by_user_uuid": true},
 665                 "authorized_keys/" + arvadostest.AdminAuthorizedKeysUUID:       {"href": true},
 666                 "collections/" + arvadostest.CollectionWithUniqueWordsUUID:     {"href": true},
 667                 "containers/" + arvadostest.RunningContainerUUID:               nil,
 668                 "container_requests/" + arvadostest.QueuedContainerRequestUUID: nil,
 669                 "groups/" + arvadostest.AProjectUUID:                           nil,
 670                 "keep_services/" + ksUUID:                                      nil,
 671                 "links/" + arvadostest.ActiveUserCanReadAllUsersLinkUUID:       nil,
 672                 "logs/" + arvadostest.CrunchstatForRunningContainerLogUUID:     nil,
 673                 "users/" + arvadostest.ActiveUserUUID:                          {"href": true},
 674                 "virtual_machines/" + arvadostest.TestVMUUID:                   nil,
 675                 "workflows/" + arvadostest.WorkflowWithDefinitionYAMLUUID:      nil,
 676         }
 677         for url, skippedFields := range testCases {
 678                 c.Logf("Testing %q", url)
 679                 s.CheckObjectType(c, "/arvados/v1/"+url, auth.TokenV2(), skippedFields)
 680         }
 681 }
 682
 683 func (s *HandlerSuite) TestRedactRailsAPIHostFromErrors(c *check.C) {
 684         req := httptest.NewRequest("GET", "https://0.0.0.0:1/arvados/v1/collections/zzzzz-4zz18-abcdefghijklmno", nil)
 685         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 686         resp := httptest.NewRecorder()
 687         s.handler.ServeHTTP(resp, req)
 688         c.Check(resp.Code, check.Equals, http.StatusNotFound)
 689         var jresp struct {
 690                 Errors []string
 691         }
 692         c.Log(resp.Body.String())
 693         c.Assert(json.NewDecoder(resp.Body).Decode(&jresp), check.IsNil)
 694         c.Assert(jresp.Errors, check.HasLen, 1)
 695         c.Check(jresp.Errors[0], check.Matches, `.*//railsapi\.internal/arvados/v1/collections/.*: 404 Not Found.*`)
 696         c.Check(jresp.Errors[0], check.Not(check.Matches), `(?ms).*127.0.0.1.*`)
 697 }
 698
 699 func (s *HandlerSuite) TestTrashSweep(c *check.C) {
 700         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 701         s.cluster.Collections.TrashSweepInterval = arvados.Duration(time.Second / 10)
 702         s.handler.CheckHealth()
 703         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
 704         coll, err := s.handler.federation.CollectionCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{"name": "test trash sweep"}, EnsureUniqueName: true})
 705         c.Assert(err, check.IsNil)
 706         defer s.handler.federation.CollectionDelete(ctx, arvados.DeleteOptions{UUID: coll.UUID})
 707         db, err := s.handler.dbConnector.GetDB(s.ctx)
 708         c.Assert(err, check.IsNil)
 709         _, 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)
 710         c.Assert(err, check.IsNil)
 711         deadline := time.Now().Add(5 * time.Second)
 712         for {
 713                 if time.Now().After(deadline) {
 714                         c.Log("timed out")
 715                         c.FailNow()
 716                 }
 717                 updated, err := s.handler.federation.CollectionGet(ctx, arvados.GetOptions{UUID: coll.UUID, IncludeTrash: true})
 718                 c.Assert(err, check.IsNil)
 719                 if updated.IsTrashed {
 720                         break
 721                 }
 722                 time.Sleep(time.Second / 10)
 723         }
 724 }
 725
 726 func (s *HandlerSuite) TestContainerLogSweep(c *check.C) {
 727         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 728         s.cluster.Collections.TrashSweepInterval = arvados.Duration(2 * time.Second)
 729         s.handler.CheckHealth()
 730         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
 731         logentry, err := s.handler.federation.LogCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{
 732                 "object_uuid": arvadostest.CompletedContainerUUID,
 733                 "event_type":  "stderr",
 734                 "properties": map[string]interface{}{
 735                         "text": "test container log sweep\n",
 736                 },
 737         }})
 738         c.Assert(err, check.IsNil)
 739         defer s.handler.federation.LogDelete(ctx, arvados.DeleteOptions{UUID: logentry.UUID})
 740         deadline := time.Now().Add(5 * time.Second)
 741         for {
 742                 if time.Now().After(deadline) {
 743                         c.Log("timed out")
 744                         c.FailNow()
 745                 }
 746                 logentries, err := s.handler.federation.LogList(ctx, arvados.ListOptions{Filters: []arvados.Filter{{"uuid", "=", logentry.UUID}}, Limit: -1})
 747                 c.Assert(err, check.IsNil)
 748                 if len(logentries.Items) == 0 {
 749                         break
 750                 }
 751                 time.Sleep(time.Second / 10)
 752         }
 753 }
 754
 755 func (s *HandlerSuite) TestLogActivity(c *check.C) {
 756         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 757         s.cluster.Users.ActivityLoggingPeriod = arvados.Duration(24 * time.Hour)
 758         s.handler.CheckHealth()
 759
 760         testServer := newServerFromIntegrationTestEnv(c)
 761         testServer.Server.Handler = httpserver.AddRequestIDs(httpserver.LogRequests(s.handler))
 762         c.Assert(testServer.Start(), check.IsNil)
 763         defer testServer.Close()
 764
 765         u, _ := url.Parse("http://" + testServer.Addr)
 766         client := rpc.NewConn(s.cluster.ClusterID, u, true, rpc.PassthroughTokenProvider)
 767
 768         starttime := time.Now()
 769         for i := 0; i < 4; i++ {
 770                 for _, token := range []string{
 771                         arvadostest.ActiveTokenV2,
 772                         arvadostest.ActiveToken,
 773                         arvadostest.SpectatorToken,
 774                 } {
 775                         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{token}})
 776                         _, err := client.CollectionList(ctx, arvados.ListOptions{})
 777                         c.Assert(err, check.IsNil)
 778                 }
 779         }
 780         db, err := s.handler.dbConnector.GetDB(s.ctx)
 781         c.Assert(err, check.IsNil)
 782         for _, userUUID := range []string{arvadostest.ActiveUserUUID, arvadostest.SpectatorUserUUID} {
 783                 var rows int
 784                 err = db.QueryRowContext(s.ctx, `select count(uuid) from logs where object_uuid = $1 and event_at > $2`, arvadostest.ActiveUserUUID, starttime.UTC()).Scan(&rows)
 785                 c.Assert(err, check.IsNil)
 786                 c.Check(rows, check.Equals, 1, check.Commentf("expect 1 row for user uuid %s", userUUID))
 787         }
 788 }
 789
 790 func (s *HandlerSuite) TestLogLimiting(c *check.C) {
 791         s.handler.Cluster.API.MaxConcurrentRequests = 2
 792         s.handler.Cluster.API.LogCreateRequestFraction = 0.5
 793
 794         logreq := httptest.NewRequest("POST", "/arvados/v1/logs", strings.NewReader(`{
 795                         "log": {
 796                           "event_type": "test"
 797                         }
 798                 }`))
 799         logreq.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 800
 801         // Log create succeeds
 802         for i := 0; i < 2; i++ {
 803                 resp := httptest.NewRecorder()
 804                 s.handler.ServeHTTP(resp, logreq)
 805                 c.Check(resp.Code, check.Equals, http.StatusOK)
 806                 var lg arvados.Log
 807                 err := json.Unmarshal(resp.Body.Bytes(), &lg)
 808                 c.Check(err, check.IsNil)
 809                 c.Check(lg.UUID, check.Matches, "zzzzz-57u5n-.*")
 810         }
 811
 812         // Pretend there's a log create in flight
 813         s.handler.limitLogCreate <- struct{}{}
 814
 815         // Log create should be rejected now
 816         resp := httptest.NewRecorder()
 817         s.handler.ServeHTTP(resp, logreq)
 818         c.Check(resp.Code, check.Equals, http.StatusServiceUnavailable)
 819
 820         // Other requests still succeed
 821         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 822         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 823         resp = httptest.NewRecorder()
 824         s.handler.ServeHTTP(resp, req)
 825         c.Check(resp.Code, check.Equals, http.StatusOK)
 826         var u arvados.User
 827         err := json.Unmarshal(resp.Body.Bytes(), &u)
 828         c.Check(err, check.IsNil)
 829         c.Check(u.UUID, check.Equals, arvadostest.ActiveUserUUID)
 830
 831         // log create still fails
 832         resp = httptest.NewRecorder()
 833         s.handler.ServeHTTP(resp, logreq)
 834         c.Check(resp.Code, check.Equals, http.StatusServiceUnavailable)
 835
 836         // Pretend in-flight log is done
 837         <-s.handler.limitLogCreate
 838
 839         // log create succeeds again
 840         resp = httptest.NewRecorder()
 841         s.handler.ServeHTTP(resp, logreq)
 842         c.Check(resp.Code, check.Equals, http.StatusOK)
 843
 844 }