14807: Tweak log message.
[arvados.git] / lib / dispatchcloud / test / stub_driver.go
1 // Copyright (C) The Arvados Authors. All rights reserved.
2 //
3 // SPDX-License-Identifier: AGPL-3.0
4
5 package test
6
7 import (
8         "crypto/rand"
9         "encoding/json"
10         "errors"
11         "fmt"
12         "io"
13         "io/ioutil"
14         math_rand "math/rand"
15         "regexp"
16         "strings"
17         "sync"
18         "time"
19
20         "git.curoverse.com/arvados.git/lib/cloud"
21         "git.curoverse.com/arvados.git/sdk/go/arvados"
22         "github.com/sirupsen/logrus"
23         "golang.org/x/crypto/ssh"
24 )
25
26 // A StubDriver implements cloud.Driver by setting up local SSH
27 // servers that do fake command executions.
28 type StubDriver struct {
29         HostKey        ssh.Signer
30         AuthorizedKeys []ssh.PublicKey
31
32         // SetupVM, if set, is called upon creation of each new
33         // StubVM. This is the caller's opportunity to customize the
34         // VM's error rate and other behaviors.
35         SetupVM func(*StubVM)
36
37         // StubVM's fake crunch-run uses this Queue to read and update
38         // container state.
39         Queue *Queue
40
41         // Frequency of artificially introduced errors on calls to
42         // Destroy. 0=always succeed, 1=always fail.
43         ErrorRateDestroy float64
44
45         // If Create() or Instances() is called too frequently, return
46         // rate-limiting errors.
47         MinTimeBetweenCreateCalls    time.Duration
48         MinTimeBetweenInstancesCalls time.Duration
49
50         // If true, Create and Destroy calls block until Release() is
51         // called.
52         HoldCloudOps bool
53
54         instanceSets []*StubInstanceSet
55         holdCloudOps chan bool
56 }
57
58 // InstanceSet returns a new *StubInstanceSet.
59 func (sd *StubDriver) InstanceSet(params json.RawMessage, id cloud.InstanceSetID, logger logrus.FieldLogger) (cloud.InstanceSet, error) {
60         if sd.holdCloudOps == nil {
61                 sd.holdCloudOps = make(chan bool)
62         }
63         sis := StubInstanceSet{
64                 driver:  sd,
65                 logger:  logger,
66                 servers: map[cloud.InstanceID]*StubVM{},
67         }
68         sd.instanceSets = append(sd.instanceSets, &sis)
69
70         var err error
71         if params != nil {
72                 err = json.Unmarshal(params, &sis)
73         }
74         return &sis, err
75 }
76
77 // InstanceSets returns all instances that have been created by the
78 // driver. This can be used to test a component that uses the driver
79 // but doesn't expose the InstanceSets it has created.
80 func (sd *StubDriver) InstanceSets() []*StubInstanceSet {
81         return sd.instanceSets
82 }
83
84 // ReleaseCloudOps releases n pending Create/Destroy calls. If there
85 // are fewer than n blocked calls pending, it waits for the rest to
86 // arrive.
87 func (sd *StubDriver) ReleaseCloudOps(n int) {
88         for i := 0; i < n; i++ {
89                 <-sd.holdCloudOps
90         }
91 }
92
93 type StubInstanceSet struct {
94         driver  *StubDriver
95         logger  logrus.FieldLogger
96         servers map[cloud.InstanceID]*StubVM
97         mtx     sync.RWMutex
98         stopped bool
99
100         allowCreateCall    time.Time
101         allowInstancesCall time.Time
102 }
103
104 func (sis *StubInstanceSet) Create(it arvados.InstanceType, image cloud.ImageID, tags cloud.InstanceTags, cmd cloud.InitCommand, authKey ssh.PublicKey) (cloud.Instance, error) {
105         if sis.driver.HoldCloudOps {
106                 sis.driver.holdCloudOps <- true
107         }
108         sis.mtx.Lock()
109         defer sis.mtx.Unlock()
110         if sis.stopped {
111                 return nil, errors.New("StubInstanceSet: Create called after Stop")
112         }
113         if sis.allowCreateCall.After(time.Now()) {
114                 return nil, RateLimitError{sis.allowCreateCall}
115         } else {
116                 sis.allowCreateCall = time.Now().Add(sis.driver.MinTimeBetweenCreateCalls)
117         }
118
119         ak := sis.driver.AuthorizedKeys
120         if authKey != nil {
121                 ak = append([]ssh.PublicKey{authKey}, ak...)
122         }
123         svm := &StubVM{
124                 sis:          sis,
125                 id:           cloud.InstanceID(fmt.Sprintf("stub-%s-%x", it.ProviderType, math_rand.Int63())),
126                 tags:         copyTags(tags),
127                 providerType: it.ProviderType,
128                 initCommand:  cmd,
129                 running:      map[string]int64{},
130                 killing:      map[string]bool{},
131         }
132         svm.SSHService = SSHService{
133                 HostKey:        sis.driver.HostKey,
134                 AuthorizedUser: "root",
135                 AuthorizedKeys: ak,
136                 Exec:           svm.Exec,
137         }
138         if setup := sis.driver.SetupVM; setup != nil {
139                 setup(svm)
140         }
141         sis.servers[svm.id] = svm
142         return svm.Instance(), nil
143 }
144
145 func (sis *StubInstanceSet) Instances(cloud.InstanceTags) ([]cloud.Instance, error) {
146         sis.mtx.RLock()
147         defer sis.mtx.RUnlock()
148         if sis.allowInstancesCall.After(time.Now()) {
149                 return nil, RateLimitError{sis.allowInstancesCall}
150         } else {
151                 sis.allowInstancesCall = time.Now().Add(sis.driver.MinTimeBetweenInstancesCalls)
152         }
153         var r []cloud.Instance
154         for _, ss := range sis.servers {
155                 r = append(r, ss.Instance())
156         }
157         return r, nil
158 }
159
160 func (sis *StubInstanceSet) Stop() {
161         sis.mtx.Lock()
162         defer sis.mtx.Unlock()
163         if sis.stopped {
164                 panic("Stop called twice")
165         }
166         sis.stopped = true
167 }
168
169 type RateLimitError struct{ Retry time.Time }
170
171 func (e RateLimitError) Error() string            { return fmt.Sprintf("rate limited until %s", e.Retry) }
172 func (e RateLimitError) EarliestRetry() time.Time { return e.Retry }
173
174 // StubVM is a fake server that runs an SSH service. It represents a
175 // VM running in a fake cloud.
176 //
177 // Note this is distinct from a stubInstance, which is a snapshot of
178 // the VM's metadata. Like a VM in a real cloud, a StubVM keeps
179 // running (and might change IP addresses, shut down, etc.)  without
180 // updating any stubInstances that have been returned to callers.
181 type StubVM struct {
182         Boot                  time.Time
183         Broken                time.Time
184         CrunchRunMissing      bool
185         CrunchRunCrashRate    float64
186         CrunchRunDetachDelay  time.Duration
187         ExecuteContainer      func(arvados.Container) int
188         CrashRunningContainer func(arvados.Container)
189
190         sis          *StubInstanceSet
191         id           cloud.InstanceID
192         tags         cloud.InstanceTags
193         initCommand  cloud.InitCommand
194         providerType string
195         SSHService   SSHService
196         running      map[string]int64
197         killing      map[string]bool
198         lastPID      int64
199         sync.Mutex
200 }
201
202 func (svm *StubVM) Instance() stubInstance {
203         svm.Lock()
204         defer svm.Unlock()
205         return stubInstance{
206                 svm:  svm,
207                 addr: svm.SSHService.Address(),
208                 // We deliberately return a cached/stale copy of the
209                 // real tags here, so that (Instance)Tags() sometimes
210                 // returns old data after a call to
211                 // (Instance)SetTags().  This is permitted by the
212                 // driver interface, and this might help remind
213                 // callers that they need to tolerate it.
214                 tags: copyTags(svm.tags),
215         }
216 }
217
218 func (svm *StubVM) Exec(env map[string]string, command string, stdin io.Reader, stdout, stderr io.Writer) uint32 {
219         stdinData, err := ioutil.ReadAll(stdin)
220         if err != nil {
221                 fmt.Fprintf(stderr, "error reading stdin: %s\n", err)
222                 return 1
223         }
224         queue := svm.sis.driver.Queue
225         uuid := regexp.MustCompile(`.{5}-dz642-.{15}`).FindString(command)
226         if eta := svm.Boot.Sub(time.Now()); eta > 0 {
227                 fmt.Fprintf(stderr, "stub is booting, ETA %s\n", eta)
228                 return 1
229         }
230         if !svm.Broken.IsZero() && svm.Broken.Before(time.Now()) {
231                 fmt.Fprintf(stderr, "cannot fork\n")
232                 return 2
233         }
234         if svm.CrunchRunMissing && strings.Contains(command, "crunch-run") {
235                 fmt.Fprint(stderr, "crunch-run: command not found\n")
236                 return 1
237         }
238         if strings.HasPrefix(command, "crunch-run --detach --stdin-env ") {
239                 var stdinKV map[string]string
240                 err := json.Unmarshal(stdinData, &stdinKV)
241                 if err != nil {
242                         fmt.Fprintf(stderr, "unmarshal stdin: %s (stdin was: %q)\n", err, stdinData)
243                         return 1
244                 }
245                 for _, name := range []string{"ARVADOS_API_HOST", "ARVADOS_API_TOKEN"} {
246                         if stdinKV[name] == "" {
247                                 fmt.Fprintf(stderr, "%s env var missing from stdin %q\n", name, stdin)
248                                 return 1
249                         }
250                 }
251                 svm.Lock()
252                 svm.lastPID++
253                 pid := svm.lastPID
254                 svm.running[uuid] = pid
255                 svm.Unlock()
256                 time.Sleep(svm.CrunchRunDetachDelay)
257                 fmt.Fprintf(stderr, "starting %s\n", uuid)
258                 logger := svm.sis.logger.WithFields(logrus.Fields{
259                         "Instance":      svm.id,
260                         "ContainerUUID": uuid,
261                         "PID":           pid,
262                 })
263                 logger.Printf("[test] starting crunch-run stub")
264                 go func() {
265                         crashluck := math_rand.Float64()
266                         ctr, ok := queue.Get(uuid)
267                         if !ok {
268                                 logger.Print("[test] container not in queue")
269                                 return
270                         }
271
272                         defer func() {
273                                 if ctr.State == arvados.ContainerStateRunning && svm.CrashRunningContainer != nil {
274                                         svm.CrashRunningContainer(ctr)
275                                 }
276                         }()
277
278                         if crashluck > svm.CrunchRunCrashRate/2 {
279                                 time.Sleep(time.Duration(math_rand.Float64()*20) * time.Millisecond)
280                                 ctr.State = arvados.ContainerStateRunning
281                                 if !queue.Notify(ctr) {
282                                         ctr, _ = queue.Get(uuid)
283                                         logger.Print("[test] erroring out because state=Running update was rejected")
284                                         return
285                                 }
286                         }
287
288                         time.Sleep(time.Duration(math_rand.Float64()*20) * time.Millisecond)
289
290                         svm.Lock()
291                         defer svm.Unlock()
292                         if svm.running[uuid] != pid {
293                                 logger.Print("[test] container was killed")
294                                 return
295                         }
296                         delete(svm.running, uuid)
297
298                         if crashluck < svm.CrunchRunCrashRate {
299                                 logger.WithField("State", ctr.State).Print("[test] crashing crunch-run stub")
300                         } else {
301                                 if svm.ExecuteContainer != nil {
302                                         ctr.ExitCode = svm.ExecuteContainer(ctr)
303                                 }
304                                 logger.WithField("ExitCode", ctr.ExitCode).Print("[test] exiting crunch-run stub")
305                                 ctr.State = arvados.ContainerStateComplete
306                                 go queue.Notify(ctr)
307                         }
308                 }()
309                 return 0
310         }
311         if command == "crunch-run --list" {
312                 svm.Lock()
313                 defer svm.Unlock()
314                 for uuid := range svm.running {
315                         fmt.Fprintf(stdout, "%s\n", uuid)
316                 }
317                 return 0
318         }
319         if strings.HasPrefix(command, "crunch-run --kill ") {
320                 svm.Lock()
321                 pid, running := svm.running[uuid]
322                 if running && !svm.killing[uuid] {
323                         svm.killing[uuid] = true
324                         go func() {
325                                 time.Sleep(time.Duration(math_rand.Float64()*30) * time.Millisecond)
326                                 svm.Lock()
327                                 defer svm.Unlock()
328                                 if svm.running[uuid] == pid {
329                                         // Kill only if the running entry
330                                         // hasn't since been killed and
331                                         // replaced with a different one.
332                                         delete(svm.running, uuid)
333                                 }
334                                 delete(svm.killing, uuid)
335                         }()
336                         svm.Unlock()
337                         time.Sleep(time.Duration(math_rand.Float64()*2) * time.Millisecond)
338                         svm.Lock()
339                         _, running = svm.running[uuid]
340                 }
341                 svm.Unlock()
342                 if running {
343                         fmt.Fprintf(stderr, "%s: container is running\n", uuid)
344                         return 1
345                 } else {
346                         fmt.Fprintf(stderr, "%s: container is not running\n", uuid)
347                         return 0
348                 }
349         }
350         if command == "true" {
351                 return 0
352         }
353         fmt.Fprintf(stderr, "%q: command not found", command)
354         return 1
355 }
356
357 type stubInstance struct {
358         svm  *StubVM
359         addr string
360         tags cloud.InstanceTags
361 }
362
363 func (si stubInstance) ID() cloud.InstanceID {
364         return si.svm.id
365 }
366
367 func (si stubInstance) Address() string {
368         return si.addr
369 }
370
371 func (si stubInstance) RemoteUser() string {
372         return si.svm.SSHService.AuthorizedUser
373 }
374
375 func (si stubInstance) Destroy() error {
376         sis := si.svm.sis
377         if sis.driver.HoldCloudOps {
378                 sis.driver.holdCloudOps <- true
379         }
380         if math_rand.Float64() < si.svm.sis.driver.ErrorRateDestroy {
381                 return errors.New("instance could not be destroyed")
382         }
383         si.svm.SSHService.Close()
384         sis.mtx.Lock()
385         defer sis.mtx.Unlock()
386         delete(sis.servers, si.svm.id)
387         return nil
388 }
389
390 func (si stubInstance) ProviderType() string {
391         return si.svm.providerType
392 }
393
394 func (si stubInstance) SetTags(tags cloud.InstanceTags) error {
395         tags = copyTags(tags)
396         svm := si.svm
397         go func() {
398                 svm.Lock()
399                 defer svm.Unlock()
400                 svm.tags = tags
401         }()
402         return nil
403 }
404
405 func (si stubInstance) Tags() cloud.InstanceTags {
406         // Return a copy to ensure a caller can't change our saved
407         // tags just by writing to the returned map.
408         return copyTags(si.tags)
409 }
410
411 func (si stubInstance) String() string {
412         return string(si.svm.id)
413 }
414
415 func (si stubInstance) VerifyHostKey(key ssh.PublicKey, client *ssh.Client) error {
416         buf := make([]byte, 512)
417         _, err := io.ReadFull(rand.Reader, buf)
418         if err != nil {
419                 return err
420         }
421         sig, err := si.svm.sis.driver.HostKey.Sign(rand.Reader, buf)
422         if err != nil {
423                 return err
424         }
425         return key.Verify(buf, sig)
426 }
427
428 func copyTags(src cloud.InstanceTags) cloud.InstanceTags {
429         dst := cloud.InstanceTags{}
430         for k, v := range src {
431                 dst[k] = v
432         }
433         return dst
434 }