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