X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/e60cae2f887a433b2bae0921bfdfed4096c9cbd6..65b12213f740b117fb14822bce0dbb415257c355:/lib/controller/handler_test.go diff --git a/lib/controller/handler_test.go b/lib/controller/handler_test.go index f854079f97..c9999fa28c 100644 --- a/lib/controller/handler_test.go +++ b/lib/controller/handler_test.go @@ -5,9 +5,11 @@ package controller import ( + "bytes" "context" "crypto/tls" "encoding/json" + "io" "io/ioutil" "net/http" "net/http/httptest" @@ -17,6 +19,7 @@ import ( "testing" "time" + "git.arvados.org/arvados.git/lib/controller/rpc" "git.arvados.org/arvados.git/sdk/go/arvados" "git.arvados.org/arvados.git/sdk/go/arvadostest" "git.arvados.org/arvados.git/sdk/go/auth" @@ -35,14 +38,16 @@ var _ = check.Suite(&HandlerSuite{}) type HandlerSuite struct { cluster *arvados.Cluster - handler http.Handler + handler *Handler + logbuf *bytes.Buffer ctx context.Context cancel context.CancelFunc } func (s *HandlerSuite) SetUpTest(c *check.C) { + s.logbuf = &bytes.Buffer{} s.ctx, s.cancel = context.WithCancel(context.Background()) - s.ctx = ctxlog.Context(s.ctx, ctxlog.New(os.Stderr, "json", "debug")) + s.ctx = ctxlog.Context(s.ctx, ctxlog.New(io.MultiWriter(os.Stderr, s.logbuf), "json", "debug")) s.cluster = &arvados.Cluster{ ClusterID: "zzzzz", PostgreSQL: integrationTestCluster().PostgreSQL, @@ -51,7 +56,7 @@ func (s *HandlerSuite) SetUpTest(c *check.C) { s.cluster.TLS.Insecure = true arvadostest.SetServiceURL(&s.cluster.Services.RailsAPI, "https://"+os.Getenv("ARVADOS_TEST_API_HOST")) arvadostest.SetServiceURL(&s.cluster.Services.Controller, "http://localhost:/") - s.handler = newHandler(s.ctx, s.cluster, "", prometheus.NewRegistry()) + s.handler = newHandler(s.ctx, s.cluster, "", prometheus.NewRegistry()).(*Handler) } func (s *HandlerSuite) TearDownTest(c *check.C) { @@ -200,17 +205,21 @@ func (s *HandlerSuite) TestProxyDiscoveryDoc(c *check.C) { c.Check(len(dd.Schemas), check.Not(check.Equals), 0) } -func (s *HandlerSuite) TestRequestTimeout(c *check.C) { - s.cluster.API.RequestTimeout = arvados.Duration(time.Nanosecond) - req := httptest.NewRequest("GET", "/discovery/v1/apis/arvados/v1/rest", nil) +// Handler should give up and exit early if request context is +// cancelled due to client hangup, httpserver.HandlerWithDeadline, +// etc. +func (s *HandlerSuite) TestRequestCancel(c *check.C) { + ctx, cancel := context.WithCancel(context.Background()) + req := httptest.NewRequest("GET", "/discovery/v1/apis/arvados/v1/rest", nil).WithContext(ctx) resp := httptest.NewRecorder() + cancel() s.handler.ServeHTTP(resp, req) c.Check(resp.Code, check.Equals, http.StatusBadGateway) var jresp httpserver.ErrorResponse err := json.Unmarshal(resp.Body.Bytes(), &jresp) c.Check(err, check.IsNil) c.Assert(len(jresp.Errors), check.Equals, 1) - c.Check(jresp.Errors[0], check.Matches, `.*context deadline exceeded.*`) + c.Check(jresp.Errors[0], check.Matches, `.*context canceled`) } func (s *HandlerSuite) TestProxyWithoutToken(c *check.C) { @@ -276,7 +285,7 @@ func (s *HandlerSuite) TestLogoutGoogle(c *check.C) { func (s *HandlerSuite) TestValidateV1APIToken(c *check.C) { req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil) - user, ok, err := s.handler.(*Handler).validateAPItoken(req, arvadostest.ActiveToken) + user, ok, err := s.handler.validateAPItoken(req, arvadostest.ActiveToken) c.Assert(err, check.IsNil) c.Check(ok, check.Equals, true) c.Check(user.Authorization.UUID, check.Equals, arvadostest.ActiveTokenUUID) @@ -287,7 +296,7 @@ func (s *HandlerSuite) TestValidateV1APIToken(c *check.C) { func (s *HandlerSuite) TestValidateV2APIToken(c *check.C) { req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil) - user, ok, err := s.handler.(*Handler).validateAPItoken(req, arvadostest.ActiveTokenV2) + user, ok, err := s.handler.validateAPItoken(req, arvadostest.ActiveTokenV2) c.Assert(err, check.IsNil) c.Check(ok, check.Equals, true) c.Check(user.Authorization.UUID, check.Equals, arvadostest.ActiveTokenUUID) @@ -317,13 +326,23 @@ func (s *HandlerSuite) TestValidateRemoteToken(c *check.C) { } } +func (s *HandlerSuite) TestLogTokenUUID(c *check.C) { + req := httptest.NewRequest("GET", "https://0.0.0.0/arvados/v1/users/current", nil) + req.Header.Set("Authorization", "Bearer "+arvadostest.ActiveTokenV2) + req = req.WithContext(s.ctx) + resp := httptest.NewRecorder() + httpserver.LogRequests(s.handler).ServeHTTP(resp, req) + c.Check(resp.Code, check.Equals, http.StatusOK) + c.Check(s.logbuf.String(), check.Matches, `(?ms).*"tokenUUIDs":\["`+strings.Split(arvadostest.ActiveTokenV2, "/")[1]+`"\].*`) +} + func (s *HandlerSuite) TestCreateAPIToken(c *check.C) { req := httptest.NewRequest("GET", "/arvados/v1/users/current", nil) - auth, err := s.handler.(*Handler).createAPItoken(req, arvadostest.ActiveUserUUID, nil) + auth, err := s.handler.createAPItoken(req, arvadostest.ActiveUserUUID, nil) c.Assert(err, check.IsNil) c.Check(auth.Scopes, check.DeepEquals, []string{"all"}) - user, ok, err := s.handler.(*Handler).validateAPItoken(req, auth.TokenV2()) + user, ok, err := s.handler.validateAPItoken(req, auth.TokenV2()) c.Assert(err, check.IsNil) c.Check(ok, check.Equals, true) c.Check(user.Authorization.UUID, check.Equals, auth.UUID) @@ -367,16 +386,14 @@ func (s *HandlerSuite) CheckObjectType(c *check.C, url string, token string, ski for k := range direct { if _, ok := skippedFields[k]; ok { continue - } else if val, ok := proxied[k]; ok { - if direct["kind"] == "arvados#collection" && k == "manifest_text" { - // Tokens differ from request to request - c.Check(strings.Split(val.(string), "+A")[0], check.Equals, strings.Split(direct[k].(string), "+A")[0]) - } else { - c.Check(val, check.DeepEquals, direct[k], - check.Commentf("RailsAPI %s key %q's value %q differs from controller's %q.", direct["kind"], k, direct[k], val)) - } - } else { + } else if val, ok := proxied[k]; !ok { c.Errorf("%s's key %q missing on controller's response.", direct["kind"], k) + } else if direct["kind"] == "arvados#collection" && k == "manifest_text" { + // Tokens differ from request to request + c.Check(strings.Split(val.(string), "+A")[0], check.Equals, strings.Split(direct[k].(string), "+A")[0]) + } else { + c.Check(val, check.DeepEquals, direct[k], + check.Commentf("RailsAPI %s key %q's value %q differs from controller's %q.", direct["kind"], k, direct[k], val)) } } } @@ -392,10 +409,30 @@ func (s *HandlerSuite) TestGetObjects(c *check.C) { json.Unmarshal(resp.Body.Bytes(), &ksList) c.Assert(len(ksList.Items), check.Not(check.Equals), 0) ksUUID := ksList.Items[0].UUID + // Create a new token for the test user so that we're not comparing + // the ones from the fixtures. + req = httptest.NewRequest("POST", "/arvados/v1/api_client_authorizations", + strings.NewReader(`{ + "api_client_authorization": { + "owner_uuid": "`+arvadostest.AdminUserUUID+`", + "created_by_ip_address": "::1", + "last_used_by_ip_address": "::1", + "default_owner_uuid": "`+arvadostest.AdminUserUUID+`" + } + }`)) + req.Header.Set("Authorization", "Bearer "+arvadostest.SystemRootToken) + req.Header.Set("Content-type", "application/json") + resp = httptest.NewRecorder() + s.handler.ServeHTTP(resp, req) + c.Assert(resp.Code, check.Equals, http.StatusOK, + check.Commentf("%s", resp.Body.String())) + var auth arvados.APIClientAuthorization + json.Unmarshal(resp.Body.Bytes(), &auth) + c.Assert(auth.UUID, check.Not(check.Equals), "") testCases := map[string]map[string]bool{ "api_clients/" + arvadostest.TrustedWorkbenchAPIClientUUID: nil, - "api_client_authorizations/" + arvadostest.AdminTokenUUID: nil, + "api_client_authorizations/" + auth.UUID: {"href": true, "modified_by_client_uuid": true, "modified_by_user_uuid": true}, "authorized_keys/" + arvadostest.AdminAuthorizedKeysUUID: nil, "collections/" + arvadostest.CollectionWithUniqueWordsUUID: {"href": true}, "containers/" + arvadostest.RunningContainerUUID: nil, @@ -411,7 +448,8 @@ func (s *HandlerSuite) TestGetObjects(c *check.C) { "workflows/" + arvadostest.WorkflowWithDefinitionYAMLUUID: nil, } for url, skippedFields := range testCases { - s.CheckObjectType(c, "/arvados/v1/"+url, arvadostest.AdminToken, skippedFields) + c.Logf("Testing %q", url) + s.CheckObjectType(c, "/arvados/v1/"+url, auth.TokenV2(), skippedFields) } } @@ -430,3 +468,94 @@ func (s *HandlerSuite) TestRedactRailsAPIHostFromErrors(c *check.C) { c.Check(jresp.Errors[0], check.Matches, `.*//railsapi\.internal/arvados/v1/collections/.*: 404 Not Found.*`) c.Check(jresp.Errors[0], check.Not(check.Matches), `(?ms).*127.0.0.1.*`) } + +func (s *HandlerSuite) TestTrashSweep(c *check.C) { + s.cluster.SystemRootToken = arvadostest.SystemRootToken + s.cluster.Collections.TrashSweepInterval = arvados.Duration(time.Second / 10) + s.handler.CheckHealth() + ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}}) + coll, err := s.handler.federation.CollectionCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{"name": "test trash sweep"}, EnsureUniqueName: true}) + c.Assert(err, check.IsNil) + defer s.handler.federation.CollectionDelete(ctx, arvados.DeleteOptions{UUID: coll.UUID}) + db, err := s.handler.dbConnector.GetDB(s.ctx) + c.Assert(err, check.IsNil) + _, 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) + c.Assert(err, check.IsNil) + deadline := time.Now().Add(5 * time.Second) + for { + if time.Now().After(deadline) { + c.Log("timed out") + c.FailNow() + } + updated, err := s.handler.federation.CollectionGet(ctx, arvados.GetOptions{UUID: coll.UUID, IncludeTrash: true}) + c.Assert(err, check.IsNil) + if updated.IsTrashed { + break + } + time.Sleep(time.Second / 10) + } +} + +func (s *HandlerSuite) TestContainerLogSweep(c *check.C) { + s.cluster.SystemRootToken = arvadostest.SystemRootToken + s.cluster.Containers.Logging.SweepInterval = arvados.Duration(time.Second / 10) + s.handler.CheckHealth() + ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{arvadostest.ActiveTokenV2}}) + logentry, err := s.handler.federation.LogCreate(ctx, arvados.CreateOptions{Attrs: map[string]interface{}{ + "object_uuid": arvadostest.CompletedContainerUUID, + "event_type": "stderr", + "properties": map[string]interface{}{ + "text": "test trash sweep\n", + }, + }}) + c.Assert(err, check.IsNil) + defer s.handler.federation.LogDelete(ctx, arvados.DeleteOptions{UUID: logentry.UUID}) + deadline := time.Now().Add(5 * time.Second) + for { + if time.Now().After(deadline) { + c.Log("timed out") + c.FailNow() + } + logentries, err := s.handler.federation.LogList(ctx, arvados.ListOptions{Filters: []arvados.Filter{{"uuid", "=", logentry.UUID}}, Limit: -1}) + c.Assert(err, check.IsNil) + if len(logentries.Items) == 0 { + break + } + time.Sleep(time.Second / 10) + } +} + +func (s *HandlerSuite) TestLogActivity(c *check.C) { + s.cluster.SystemRootToken = arvadostest.SystemRootToken + s.cluster.Users.ActivityLoggingPeriod = arvados.Duration(24 * time.Hour) + s.handler.CheckHealth() + + testServer := newServerFromIntegrationTestEnv(c) + testServer.Server.Handler = httpserver.AddRequestIDs(httpserver.LogRequests(s.handler)) + c.Assert(testServer.Start(), check.IsNil) + defer testServer.Close() + + u, _ := url.Parse("http://" + testServer.Addr) + client := rpc.NewConn(s.cluster.ClusterID, u, true, rpc.PassthroughTokenProvider) + + starttime := time.Now() + for i := 0; i < 4; i++ { + for _, token := range []string{ + arvadostest.ActiveTokenV2, + arvadostest.ActiveToken, + arvadostest.SpectatorToken, + } { + ctx := auth.NewContext(s.ctx, &auth.Credentials{Tokens: []string{token}}) + _, err := client.CollectionList(ctx, arvados.ListOptions{}) + c.Assert(err, check.IsNil) + } + } + db, err := s.handler.dbConnector.GetDB(s.ctx) + c.Assert(err, check.IsNil) + for _, userUUID := range []string{arvadostest.ActiveUserUUID, arvadostest.SpectatorUserUUID} { + var rows int + err = db.QueryRowContext(s.ctx, `select count(uuid) from logs where object_uuid = $1 and event_at > $2`, arvadostest.ActiveUserUUID, starttime.UTC()).Scan(&rows) + c.Assert(err, check.IsNil) + c.Check(rows, check.Equals, 1, check.Commentf("expect 1 row for user uuid %s", userUUID)) + } +}