lib/dispatchcloud/dispatcher_test.go

   1 // Copyright (C) The Arvados Authors. All rights reserved.
   2 //
   3 // SPDX-License-Identifier: AGPL-3.0
   4
   5 package dispatchcloud
   6
   7 import (
   8         "context"
   9         "crypto/tls"
  10         "encoding/json"
  11         "io/ioutil"
  12         "math/rand"
  13         "net/http"
  14         "net/http/httptest"
  15         "net/url"
  16         "os"
  17         "sync"
  18         "time"
  19
  20         "git.arvados.org/arvados.git/lib/config"
  21         "git.arvados.org/arvados.git/lib/dispatchcloud/test"
  22         "git.arvados.org/arvados.git/sdk/go/arvados"
  23         "git.arvados.org/arvados.git/sdk/go/arvadostest"
  24         "git.arvados.org/arvados.git/sdk/go/ctxlog"
  25         "github.com/prometheus/client_golang/prometheus"
  26         "golang.org/x/crypto/ssh"
  27         check "gopkg.in/check.v1"
  28 )
  29
  30 var _ = check.Suite(&DispatcherSuite{})
  31
  32 type DispatcherSuite struct {
  33         ctx            context.Context
  34         cancel         context.CancelFunc
  35         cluster        *arvados.Cluster
  36         stubDriver     *test.StubDriver
  37         disp           *dispatcher
  38         error503Server *httptest.Server
  39 }
  40
  41 func (s *DispatcherSuite) SetUpTest(c *check.C) {
  42         s.ctx, s.cancel = context.WithCancel(context.Background())
  43         s.ctx = ctxlog.Context(s.ctx, ctxlog.TestLogger(c))
  44         dispatchpub, _ := test.LoadTestKey(c, "test/sshkey_dispatch")
  45         dispatchprivraw, err := ioutil.ReadFile("test/sshkey_dispatch")
  46         c.Assert(err, check.IsNil)
  47
  48         _, hostpriv := test.LoadTestKey(c, "test/sshkey_vm")
  49         s.stubDriver = &test.StubDriver{
  50                 HostKey:                   hostpriv,
  51                 AuthorizedKeys:            []ssh.PublicKey{dispatchpub},
  52                 ErrorRateDestroy:          0.1,
  53                 MinTimeBetweenCreateCalls: time.Millisecond,
  54         }
  55
  56         // We need the postgresql connection info from the integration
  57         // test config.
  58         cfg, err := config.NewLoader(nil, ctxlog.FromContext(s.ctx)).Load()
  59         c.Assert(err, check.IsNil)
  60         testcluster, err := cfg.GetCluster("")
  61         c.Assert(err, check.IsNil)
  62
  63         s.cluster = &arvados.Cluster{
  64                 ManagementToken: "test-management-token",
  65                 PostgreSQL:      testcluster.PostgreSQL,
  66                 Containers: arvados.ContainersConfig{
  67                         CrunchRunCommand:       "crunch-run",
  68                         CrunchRunArgumentsList: []string{"--foo", "--extra='args'"},
  69                         DispatchPrivateKey:     string(dispatchprivraw),
  70                         StaleLockTimeout:       arvados.Duration(5 * time.Millisecond),
  71                         RuntimeEngine:          "stub",
  72                         CloudVMs: arvados.CloudVMsConfig{
  73                                 Driver:               "test",
  74                                 SyncInterval:         arvados.Duration(10 * time.Millisecond),
  75                                 TimeoutIdle:          arvados.Duration(150 * time.Millisecond),
  76                                 TimeoutBooting:       arvados.Duration(150 * time.Millisecond),
  77                                 TimeoutProbe:         arvados.Duration(15 * time.Millisecond),
  78                                 TimeoutShutdown:      arvados.Duration(5 * time.Millisecond),
  79                                 MaxCloudOpsPerSecond: 500,
  80                                 PollInterval:         arvados.Duration(5 * time.Millisecond),
  81                                 ProbeInterval:        arvados.Duration(5 * time.Millisecond),
  82                                 MaxProbesPerSecond:   1000,
  83                                 TimeoutSignal:        arvados.Duration(3 * time.Millisecond),
  84                                 TimeoutStaleRunLock:  arvados.Duration(3 * time.Millisecond),
  85                                 TimeoutTERM:          arvados.Duration(20 * time.Millisecond),
  86                                 ResourceTags:         map[string]string{"testtag": "test value"},
  87                                 TagKeyPrefix:         "test:",
  88                         },
  89                 },
  90                 InstanceTypes: arvados.InstanceTypeMap{
  91                         test.InstanceType(1).Name:  test.InstanceType(1),
  92                         test.InstanceType(2).Name:  test.InstanceType(2),
  93                         test.InstanceType(3).Name:  test.InstanceType(3),
  94                         test.InstanceType(4).Name:  test.InstanceType(4),
  95                         test.InstanceType(6).Name:  test.InstanceType(6),
  96                         test.InstanceType(8).Name:  test.InstanceType(8),
  97                         test.InstanceType(16).Name: test.InstanceType(16),
  98                 },
  99         }
 100         arvadostest.SetServiceURL(&s.cluster.Services.DispatchCloud, "http://localhost:/")
 101         arvadostest.SetServiceURL(&s.cluster.Services.Controller, "https://"+os.Getenv("ARVADOS_API_HOST")+"/")
 102
 103         arvClient, err := arvados.NewClientFromConfig(s.cluster)
 104         c.Assert(err, check.IsNil)
 105         // Disable auto-retry
 106         arvClient.Timeout = 0
 107
 108         s.error503Server = httptest.NewTLSServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusServiceUnavailable) }))
 109         arvClient.Client = &http.Client{
 110                 Transport: &http.Transport{
 111                         Proxy: s.arvClientProxy(c),
 112                         TLSClientConfig: &tls.Config{
 113                                 InsecureSkipVerify: true}}}
 114
 115         s.disp = &dispatcher{
 116                 Cluster:   s.cluster,
 117                 Context:   s.ctx,
 118                 ArvClient: arvClient,
 119                 AuthToken: arvadostest.AdminToken,
 120                 Registry:  prometheus.NewRegistry(),
 121         }
 122         // Test cases can modify s.cluster before calling
 123         // initialize(), and then modify private state before calling
 124         // go run().
 125 }
 126
 127 func (s *DispatcherSuite) TearDownTest(c *check.C) {
 128         s.cancel()
 129         s.disp.Close()
 130         s.error503Server.Close()
 131 }
 132
 133 // Intercept outgoing API requests for "/503" and respond HTTP
 134 // 503. This lets us force (*arvados.Client)Last503() to return
 135 // something.
 136 func (s *DispatcherSuite) arvClientProxy(c *check.C) func(*http.Request) (*url.URL, error) {
 137         return func(req *http.Request) (*url.URL, error) {
 138                 if req.URL.Path == "/503" {
 139                         return url.Parse(s.error503Server.URL)
 140                 } else {
 141                         return nil, nil
 142                 }
 143         }
 144 }
 145
 146 // DispatchToStubDriver checks that the dispatcher wires everything
 147 // together effectively. It uses a real scheduler and worker pool with
 148 // a fake queue and cloud driver. The fake cloud driver injects
 149 // artificial errors in order to exercise a variety of code paths.
 150 func (s *DispatcherSuite) TestDispatchToStubDriver(c *check.C) {
 151         Drivers["test"] = s.stubDriver
 152         s.disp.setupOnce.Do(s.disp.initialize)
 153         queue := &test.Queue{
 154                 MaxDispatchAttempts: 5,
 155                 ChooseType: func(ctr *arvados.Container) (arvados.InstanceType, error) {
 156                         return ChooseInstanceType(s.cluster, ctr)
 157                 },
 158                 Logger: ctxlog.TestLogger(c),
 159         }
 160         for i := 0; i < 200; i++ {
 161                 queue.Containers = append(queue.Containers, arvados.Container{
 162                         UUID:     test.ContainerUUID(i + 1),
 163                         State:    arvados.ContainerStateQueued,
 164                         Priority: int64(i%20 + 1),
 165                         RuntimeConstraints: arvados.RuntimeConstraints{
 166                                 RAM:   int64(i%3+1) << 30,
 167                                 VCPUs: i%8 + 1,
 168                         },
 169                 })
 170         }
 171         s.disp.queue = queue
 172
 173         var mtx sync.Mutex
 174         done := make(chan struct{})
 175         waiting := map[string]struct{}{}
 176         for _, ctr := range queue.Containers {
 177                 waiting[ctr.UUID] = struct{}{}
 178         }
 179         finishContainer := func(ctr arvados.Container) {
 180                 mtx.Lock()
 181                 defer mtx.Unlock()
 182                 if _, ok := waiting[ctr.UUID]; !ok {
 183                         c.Errorf("container completed twice: %s", ctr.UUID)
 184                         return
 185                 }
 186                 delete(waiting, ctr.UUID)
 187                 if len(waiting) == 100 {
 188                         // trigger scheduler maxConcurrency limit
 189                         s.disp.ArvClient.RequestAndDecode(nil, "GET", "503", nil, nil)
 190                 }
 191                 if len(waiting) == 0 {
 192                         close(done)
 193                 }
 194         }
 195         executeContainer := func(ctr arvados.Container) int {
 196                 finishContainer(ctr)
 197                 return int(rand.Uint32() & 0x3)
 198         }
 199         n := 0
 200         s.stubDriver.Queue = queue
 201         s.stubDriver.SetupVM = func(stubvm *test.StubVM) {
 202                 n++
 203                 stubvm.Boot = time.Now().Add(time.Duration(rand.Int63n(int64(5 * time.Millisecond))))
 204                 stubvm.CrunchRunDetachDelay = time.Duration(rand.Int63n(int64(10 * time.Millisecond)))
 205                 stubvm.ExecuteContainer = executeContainer
 206                 stubvm.CrashRunningContainer = finishContainer
 207                 stubvm.ExtraCrunchRunArgs = "'--runtime-engine=stub' '--foo' '--extra='\\''args'\\'''"
 208                 switch n % 7 {
 209                 case 0:
 210                         stubvm.Broken = time.Now().Add(time.Duration(rand.Int63n(90)) * time.Millisecond)
 211                 case 1:
 212                         stubvm.CrunchRunMissing = true
 213                 case 2:
 214                         stubvm.ReportBroken = time.Now().Add(time.Duration(rand.Int63n(200)) * time.Millisecond)
 215                 default:
 216                         stubvm.CrunchRunCrashRate = 0.1
 217                         stubvm.ArvMountDeadlockRate = 0.1
 218                 }
 219         }
 220         s.stubDriver.Bugf = c.Errorf
 221
 222         start := time.Now()
 223         go s.disp.run()
 224         err := s.disp.CheckHealth()
 225         c.Check(err, check.IsNil)
 226
 227         for len(waiting) > 0 {
 228                 waswaiting := len(waiting)
 229                 select {
 230                 case <-done:
 231                         // loop will end because len(waiting)==0
 232                 case <-time.After(3 * time.Second):
 233                         if len(waiting) >= waswaiting {
 234                                 c.Fatalf("timed out; no progress in 3s while waiting for %d containers: %q", len(waiting), waiting)
 235                         }
 236                 }
 237         }
 238         c.Logf("containers finished (%s), waiting for instances to shutdown and queue to clear", time.Since(start))
 239
 240         deadline := time.Now().Add(5 * time.Second)
 241         for range time.NewTicker(10 * time.Millisecond).C {
 242                 insts, err := s.stubDriver.InstanceSets()[0].Instances(nil)
 243                 c.Check(err, check.IsNil)
 244                 queue.Update()
 245                 ents, _ := queue.Entries()
 246                 if len(ents) == 0 && len(insts) == 0 {
 247                         break
 248                 }
 249                 if time.Now().After(deadline) {
 250                         c.Fatalf("timed out with %d containers (%v), %d instances (%+v)", len(ents), ents, len(insts), insts)
 251                 }
 252         }
 253
 254         req := httptest.NewRequest("GET", "/metrics", nil)
 255         req.Header.Set("Authorization", "Bearer "+s.cluster.ManagementToken)
 256         resp := httptest.NewRecorder()
 257         s.disp.ServeHTTP(resp, req)
 258         c.Check(resp.Code, check.Equals, http.StatusOK)
 259         c.Check(resp.Body.String(), check.Matches, `(?ms).*driver_operations{error="0",operation="Create"} [^0].*`)
 260         c.Check(resp.Body.String(), check.Matches, `(?ms).*driver_operations{error="0",operation="List"} [^0].*`)
 261         c.Check(resp.Body.String(), check.Matches, `(?ms).*driver_operations{error="0",operation="Destroy"} [^0].*`)
 262         c.Check(resp.Body.String(), check.Matches, `(?ms).*driver_operations{error="1",operation="Create"} [^0].*`)
 263         c.Check(resp.Body.String(), check.Matches, `(?ms).*driver_operations{error="1",operation="List"} 0\n.*`)
 264         c.Check(resp.Body.String(), check.Matches, `(?ms).*boot_outcomes{outcome="aborted"} [0-9]+\n.*`)
 265         c.Check(resp.Body.String(), check.Matches, `(?ms).*boot_outcomes{outcome="disappeared"} [^0].*`)
 266         c.Check(resp.Body.String(), check.Matches, `(?ms).*boot_outcomes{outcome="failure"} [^0].*`)
 267         c.Check(resp.Body.String(), check.Matches, `(?ms).*boot_outcomes{outcome="success"} [^0].*`)
 268         c.Check(resp.Body.String(), check.Matches, `(?ms).*instances_disappeared{state="shutdown"} [^0].*`)
 269         c.Check(resp.Body.String(), check.Matches, `(?ms).*instances_disappeared{state="unknown"} 0\n.*`)
 270         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_to_ssh_seconds{quantile="0.95"} [0-9.]*`)
 271         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_to_ssh_seconds_count [0-9]*`)
 272         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_to_ssh_seconds_sum [0-9.]*`)
 273         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_to_ready_for_container_seconds{quantile="0.95"} [0-9.]*`)
 274         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_to_ready_for_container_seconds_count [0-9]*`)
 275         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_to_ready_for_container_seconds_sum [0-9.]*`)
 276         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_from_shutdown_request_to_disappearance_seconds_count [0-9]*`)
 277         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_from_shutdown_request_to_disappearance_seconds_sum [0-9.]*`)
 278         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_from_queue_to_crunch_run_seconds_count [0-9]*`)
 279         c.Check(resp.Body.String(), check.Matches, `(?ms).*time_from_queue_to_crunch_run_seconds_sum [0-9e+.]*`)
 280         c.Check(resp.Body.String(), check.Matches, `(?ms).*run_probe_duration_seconds_count{outcome="success"} [0-9]*`)
 281         c.Check(resp.Body.String(), check.Matches, `(?ms).*run_probe_duration_seconds_sum{outcome="success"} [0-9e+.]*`)
 282         c.Check(resp.Body.String(), check.Matches, `(?ms).*run_probe_duration_seconds_count{outcome="fail"} [0-9]*`)
 283         c.Check(resp.Body.String(), check.Matches, `(?ms).*run_probe_duration_seconds_sum{outcome="fail"} [0-9e+.]*`)
 284         c.Check(resp.Body.String(), check.Matches, `(?ms).*last_503_time [1-9][0-9e+.]*`)
 285         c.Check(resp.Body.String(), check.Matches, `(?ms).*max_concurrent_containers [1-9][0-9e+.]*`)
 286 }
 287
 288 func (s *DispatcherSuite) TestAPIPermissions(c *check.C) {
 289         s.cluster.ManagementToken = "abcdefgh"
 290         Drivers["test"] = s.stubDriver
 291         s.disp.setupOnce.Do(s.disp.initialize)
 292         s.disp.queue = &test.Queue{}
 293         go s.disp.run()
 294
 295         for _, token := range []string{"abc", ""} {
 296                 req := httptest.NewRequest("GET", "/arvados/v1/dispatch/instances", nil)
 297                 if token != "" {
 298                         req.Header.Set("Authorization", "Bearer "+token)
 299                 }
 300                 resp := httptest.NewRecorder()
 301                 s.disp.ServeHTTP(resp, req)
 302                 if token == "" {
 303                         c.Check(resp.Code, check.Equals, http.StatusUnauthorized)
 304                 } else {
 305                         c.Check(resp.Code, check.Equals, http.StatusForbidden)
 306                 }
 307         }
 308 }
 309
 310 func (s *DispatcherSuite) TestAPIDisabled(c *check.C) {
 311         s.cluster.ManagementToken = ""
 312         Drivers["test"] = s.stubDriver
 313         s.disp.setupOnce.Do(s.disp.initialize)
 314         s.disp.queue = &test.Queue{}
 315         go s.disp.run()
 316
 317         for _, token := range []string{"abc", ""} {
 318                 req := httptest.NewRequest("GET", "/arvados/v1/dispatch/instances", nil)
 319                 if token != "" {
 320                         req.Header.Set("Authorization", "Bearer "+token)
 321                 }
 322                 resp := httptest.NewRecorder()
 323                 s.disp.ServeHTTP(resp, req)
 324                 c.Check(resp.Code, check.Equals, http.StatusForbidden)
 325         }
 326 }
 327
 328 func (s *DispatcherSuite) TestInstancesAPI(c *check.C) {
 329         s.cluster.ManagementToken = "abcdefgh"
 330         s.cluster.Containers.CloudVMs.TimeoutBooting = arvados.Duration(time.Second)
 331         Drivers["test"] = s.stubDriver
 332         s.disp.setupOnce.Do(s.disp.initialize)
 333         s.disp.queue = &test.Queue{}
 334         go s.disp.run()
 335
 336         type instance struct {
 337                 Instance             string
 338                 WorkerState          string `json:"worker_state"`
 339                 Price                float64
 340                 LastContainerUUID    string `json:"last_container_uuid"`
 341                 ArvadosInstanceType  string `json:"arvados_instance_type"`
 342                 ProviderInstanceType string `json:"provider_instance_type"`
 343         }
 344         type instancesResponse struct {
 345                 Items []instance
 346         }
 347         getInstances := func() instancesResponse {
 348                 req := httptest.NewRequest("GET", "/arvados/v1/dispatch/instances", nil)
 349                 req.Header.Set("Authorization", "Bearer abcdefgh")
 350                 resp := httptest.NewRecorder()
 351                 s.disp.ServeHTTP(resp, req)
 352                 var sr instancesResponse
 353                 c.Check(resp.Code, check.Equals, http.StatusOK)
 354                 err := json.Unmarshal(resp.Body.Bytes(), &sr)
 355                 c.Check(err, check.IsNil)
 356                 return sr
 357         }
 358
 359         sr := getInstances()
 360         c.Check(len(sr.Items), check.Equals, 0)
 361
 362         ch := s.disp.pool.Subscribe()
 363         defer s.disp.pool.Unsubscribe(ch)
 364         ok := s.disp.pool.Create(test.InstanceType(1))
 365         c.Check(ok, check.Equals, true)
 366         <-ch
 367
 368         for deadline := time.Now().Add(time.Second); time.Now().Before(deadline); {
 369                 sr = getInstances()
 370                 if len(sr.Items) > 0 {
 371                         break
 372                 }
 373                 time.Sleep(time.Millisecond)
 374         }
 375         c.Assert(len(sr.Items), check.Equals, 1)
 376         c.Check(sr.Items[0].Instance, check.Matches, "inst.*")
 377         c.Check(sr.Items[0].WorkerState, check.Equals, "booting")
 378         c.Check(sr.Items[0].Price, check.Equals, 0.123)
 379         c.Check(sr.Items[0].LastContainerUUID, check.Equals, "")
 380         c.Check(sr.Items[0].ProviderInstanceType, check.Equals, test.InstanceType(1).ProviderType)
 381         c.Check(sr.Items[0].ArvadosInstanceType, check.Equals, test.InstanceType(1).Name)
 382 }