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         c.Assert(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         err = json.Unmarshal(resp.Body.Bytes(), &proxied)
 574         c.Check(err, check.Equals, nil)
 575
 576         // Get collection directly from RailsAPI
 577         client := &http.Client{
 578                 Transport: &http.Transport{
 579                         TLSClientConfig: &tls.Config{InsecureSkipVerify: true},
 580                 },
 581         }
 582         resp2, err := client.Get(s.cluster.Services.RailsAPI.ExternalURL.String() + url + "/?api_token=" + token)
 583         c.Check(err, check.Equals, nil)
 584         c.Assert(resp2.StatusCode, check.Equals, http.StatusOK,
 585                 check.Commentf("Wasn't able to get data from the RailsAPI at %q", url))
 586         defer resp2.Body.Close()
 587         db, err := ioutil.ReadAll(resp2.Body)
 588         c.Check(err, check.Equals, nil)
 589         err = json.Unmarshal(db, &direct)
 590         c.Check(err, check.Equals, nil)
 591
 592         // Check that all RailsAPI provided keys exist on the controller response.
 593         for k := range direct {
 594                 if _, ok := skippedFields[k]; ok {
 595                         continue
 596                 } else if val, ok := proxied[k]; !ok {
 597                         c.Errorf("%s's key %q missing on controller's response.", direct["kind"], k)
 598                 } else if direct["kind"] == "arvados#collection" && k == "manifest_text" {
 599                         // Tokens differ from request to request
 600                         c.Check(strings.Split(val.(string), "+A")[0], check.Equals, strings.Split(direct[k].(string), "+A")[0])
 601                 } else {
 602                         c.Check(val, check.DeepEquals, direct[k],
 603                                 check.Commentf("RailsAPI %s key %q's value %q differs from controller's %q.", direct["kind"], k, direct[k], val))
 604                 }
 605         }
 606 }
 607
 608 func (s *HandlerSuite) TestGetObjects(c *check.C) {
 609         // Get the 1st keep service's uuid from the running test server.
 610         req := httptest.NewRequest("GET", "/arvados/v1/keep_services/", nil)
 611         req.Header.Set("Authorization", "Bearer "+arvadostest.AdminToken)
 612         resp := httptest.NewRecorder()
 613         s.handler.ServeHTTP(resp, req)
 614         c.Assert(resp.Code, check.Equals, http.StatusOK)
 615         var ksList arvados.KeepServiceList
 616         json.Unmarshal(resp.Body.Bytes(), &ksList)
 617         c.Assert(len(ksList.Items), check.Not(check.Equals), 0)
 618         ksUUID := ksList.Items[0].UUID
 619         // Create a new token for the test user so that we're not comparing
 620         // the ones from the fixtures.
 621         req = httptest.NewRequest("POST", "/arvados/v1/api_client_authorizations",
 622                 strings.NewReader(`{
 623                         "api_client_authorization": {
 624                                 "owner_uuid": "`+arvadostest.AdminUserUUID+`",
 625                                 "created_by_ip_address": "::1",
 626                                 "last_used_by_ip_address": "::1",
 627                                 "default_owner_uuid": "`+arvadostest.AdminUserUUID+`"
 628                         }
 629                 }`))
 630         req.Header.Set("Authorization", "Bearer "+arvadostest.SystemRootToken)
 631         req.Header.Set("Content-type", "application/json")
 632         resp = httptest.NewRecorder()
 633         s.handler.ServeHTTP(resp, req)
 634         c.Assert(resp.Code, check.Equals, http.StatusOK,
 635                 check.Commentf("%s", resp.Body.String()))
 636         var auth arvados.APIClientAuthorization
 637         json.Unmarshal(resp.Body.Bytes(), &auth)
 638         c.Assert(auth.UUID, check.Not(check.Equals), "")
 639
 640         testCases := map[string]map[string]bool{
 641                 "api_clients/" + arvadostest.TrustedWorkbenchAPIClientUUID:     nil,
 642                 "api_client_authorizations/" + auth.UUID:                       {"href": true, "modified_by_client_uuid": true, "modified_by_user_uuid": true},
 643                 "authorized_keys/" + arvadostest.AdminAuthorizedKeysUUID:       {"href": true},
 644                 "collections/" + arvadostest.CollectionWithUniqueWordsUUID:     {"href": true},
 645                 "containers/" + arvadostest.RunningContainerUUID:               nil,
 646                 "container_requests/" + arvadostest.QueuedContainerRequestUUID: nil,
 647                 "groups/" + arvadostest.AProjectUUID:                           nil,
 648                 "keep_services/" + ksUUID:                                      nil,
 649                 "links/" + arvadostest.ActiveUserCanReadAllUsersLinkUUID:       nil,
 650                 "logs/" + arvadostest.CrunchstatForRunningJobLogUUID:           nil,
 651                 "nodes/" + arvadostest.IdleNodeUUID:                            nil,
 652                 "repositories/" + arvadostest.ArvadosRepoUUID:                  nil,
 653                 "users/" + arvadostest.ActiveUserUUID:                          {"href": true},
 654                 "virtual_machines/" + arvadostest.TestVMUUID:                   nil,
 655                 "workflows/" + arvadostest.WorkflowWithDefinitionYAMLUUID:      nil,
 656         }
 657         for url, skippedFields := range testCases {
 658                 c.Logf("Testing %q", url)
 659                 s.CheckObjectType(c, "/arvados/v1/"+url, auth.TokenV2(), skippedFields)
 660         }
 661 }
 662
 663 func (s *HandlerSuite) TestRedactRailsAPIHostFromErrors(c *check.C) {
 664         req := httptest.NewRequest("GET", "https://0.0.0.0:1/arvados/v1/collections/zzzzz-4zz18-abcdefghijklmno", nil)
 665         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 666         resp := httptest.NewRecorder()
 667         s.handler.ServeHTTP(resp, req)
 668         c.Check(resp.Code, check.Equals, http.StatusNotFound)
 669         var jresp struct {
 670                 Errors []string
 671         }
 672         c.Log(resp.Body.String())
 673         c.Assert(json.NewDecoder(resp.Body).Decode(&jresp), check.IsNil)
 674         c.Assert(jresp.Errors, check.HasLen, 1)
 675         c.Check(jresp.Errors[0], check.Matches, `.*//railsapi\.internal/arvados/v1/collections/.*: 404 Not Found.*`)
 676         c.Check(jresp.Errors[0], check.Not(check.Matches), `(?ms).*127.0.0.1.*`)
 677 }
 678
 679 func (s *HandlerSuite) TestTrashSweep(c *check.C) {
 680         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 681         s.cluster.Collections.TrashSweepInterval = arvados.Duration(time.Second / 10)
 682         s.handler.CheckHealth()
 683         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
 684         coll, err := s.handler.federation.CollectionCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{"name": "test trash sweep"}, EnsureUniqueName: true})
 685         c.Assert(err, check.IsNil)
 686         defer s.handler.federation.CollectionDelete(ctx, arvados.DeleteOptions{UUID: coll.UUID})
 687         db, err := s.handler.dbConnector.GetDB(s.ctx)
 688         c.Assert(err, check.IsNil)
 689         _, 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)
 690         c.Assert(err, check.IsNil)
 691         deadline := time.Now().Add(5 * time.Second)
 692         for {
 693                 if time.Now().After(deadline) {
 694                         c.Log("timed out")
 695                         c.FailNow()
 696                 }
 697                 updated, err := s.handler.federation.CollectionGet(ctx, arvados.GetOptions{UUID: coll.UUID, IncludeTrash: true})
 698                 c.Assert(err, check.IsNil)
 699                 if updated.IsTrashed {
 700                         break
 701                 }
 702                 time.Sleep(time.Second / 10)
 703         }
 704 }
 705
 706 func (s *HandlerSuite) TestContainerLogSweep(c *check.C) {
 707         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 708         s.cluster.Containers.Logging.SweepInterval = arvados.Duration(time.Second / 10)
 709         s.handler.CheckHealth()
 710         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}})
 711         logentry, err := s.handler.federation.LogCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{
 712                 "object_uuid": arvadostest.CompletedContainerUUID,
 713                 "event_type":  "stderr",
 714                 "properties": map[string]interface{}{
 715                         "text": "test trash sweep\n",
 716                 },
 717         }})
 718         c.Assert(err, check.IsNil)
 719         defer s.handler.federation.LogDelete(ctx, arvados.DeleteOptions{UUID: logentry.UUID})
 720         deadline := time.Now().Add(5 * time.Second)
 721         for {
 722                 if time.Now().After(deadline) {
 723                         c.Log("timed out")
 724                         c.FailNow()
 725                 }
 726                 logentries, err := s.handler.federation.LogList(ctx, arvados.ListOptions{Filters: []arvados.Filter{{"uuid", "=", logentry.UUID}}, Limit: -1})
 727                 c.Assert(err, check.IsNil)
 728                 if len(logentries.Items) == 0 {
 729                         break
 730                 }
 731                 time.Sleep(time.Second / 10)
 732         }
 733 }
 734
 735 func (s *HandlerSuite) TestLogActivity(c *check.C) {
 736         s.cluster.SystemRootToken = arvadostest.SystemRootToken
 737         s.cluster.Users.ActivityLoggingPeriod = arvados.Duration(24 * time.Hour)
 738         s.handler.CheckHealth()
 739
 740         testServer := newServerFromIntegrationTestEnv(c)
 741         testServer.Server.Handler = httpserver.AddRequestIDs(httpserver.LogRequests(s.handler))
 742         c.Assert(testServer.Start(), check.IsNil)
 743         defer testServer.Close()
 744
 745         u, _ := url.Parse("http://" + testServer.Addr)
 746         client := rpc.NewConn(s.cluster.ClusterID, u, true, rpc.PassthroughTokenProvider)
 747
 748         starttime := time.Now()
 749         for i := 0; i < 4; i++ {
 750                 for _, token := range []string{
 751                         arvadostest.ActiveTokenV2,
 752                         arvadostest.ActiveToken,
 753                         arvadostest.SpectatorToken,
 754                 } {
 755                         ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{token}})
 756                         _, err := client.CollectionList(ctx, arvados.ListOptions{})
 757                         c.Assert(err, check.IsNil)
 758                 }
 759         }
 760         db, err := s.handler.dbConnector.GetDB(s.ctx)
 761         c.Assert(err, check.IsNil)
 762         for _, userUUID := range []string{arvadostest.ActiveUserUUID, arvadostest.SpectatorUserUUID} {
 763                 var rows int
 764                 err = db.QueryRowContext(s.ctx, `select count(uuid) from logs where object_uuid = $1 and event_at > $2`, arvadostest.ActiveUserUUID, starttime.UTC()).Scan(&rows)
 765                 c.Assert(err, check.IsNil)
 766                 c.Check(rows, check.Equals, 1, check.Commentf("expect 1 row for user uuid %s", userUUID))
 767         }
 768 }
 769
 770 func (s *HandlerSuite) TestLogLimiting(c *check.C) {
 771         s.handler.Cluster.API.MaxConcurrentRequests = 2
 772         s.handler.Cluster.API.LogCreateRequestFraction = 0.5
 773
 774         logreq := httptest.NewRequest("POST", "/arvados/v1/logs", strings.NewReader(`{
 775                         "log": {
 776                           "event_type": "test"
 777                         }
 778                 }`))
 779         logreq.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 780
 781         // Log create succeeds
 782         for i := 0; i < 2; i++ {
 783                 resp := httptest.NewRecorder()
 784                 s.handler.ServeHTTP(resp, logreq)
 785                 c.Check(resp.Code, check.Equals, http.StatusOK)
 786                 var lg arvados.Log
 787                 err := json.Unmarshal(resp.Body.Bytes(), &lg)
 788                 c.Check(err, check.IsNil)
 789                 c.Check(lg.UUID, check.Matches, "zzzzz-57u5n-.*")
 790         }
 791
 792         // Pretend there's a log create in flight
 793         s.handler.limitLogCreate <- struct{}{}
 794
 795         // Log create should be rejected now
 796         resp := httptest.NewRecorder()
 797         s.handler.ServeHTTP(resp, logreq)
 798         c.Check(resp.Code, check.Equals, http.StatusServiceUnavailable)
 799
 800         // Other requests still succeed
 801         req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil)
 802         req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveToken)
 803         resp = httptest.NewRecorder()
 804         s.handler.ServeHTTP(resp, req)
 805         c.Check(resp.Code, check.Equals, http.StatusOK)
 806         var u arvados.User
 807         err := json.Unmarshal(resp.Body.Bytes(), &u)
 808         c.Check(err, check.IsNil)
 809         c.Check(u.UUID, check.Equals, arvadostest.ActiveUserUUID)
 810
 811         // log create still fails
 812         resp = httptest.NewRecorder()
 813         s.handler.ServeHTTP(resp, logreq)
 814         c.Check(resp.Code, check.Equals, http.StatusServiceUnavailable)
 815
 816         // Pretend in-flight log is done
 817         <-s.handler.limitLogCreate
 818
 819         // log create succeeds again
 820         resp = httptest.NewRecorder()
 821         s.handler.ServeHTTP(resp, logreq)
 822         c.Check(resp.Code, check.Equals, http.StatusOK)
 823
 824 }