10846: Remove duplicate log message suppression by ComputeNodeMonitorActor
[arvados.git] / services / crunch-run / crunchrun_test.go
1 package main
2
3 import (
4         "bytes"
5         "crypto/md5"
6         "encoding/json"
7         "errors"
8         "fmt"
9         "git.curoverse.com/arvados.git/sdk/go/arvados"
10         "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
11         "git.curoverse.com/arvados.git/sdk/go/keepclient"
12         "git.curoverse.com/arvados.git/sdk/go/manifest"
13         "github.com/curoverse/dockerclient"
14         . "gopkg.in/check.v1"
15         "io"
16         "io/ioutil"
17         "os"
18         "os/exec"
19         "path/filepath"
20         "sort"
21         "strings"
22         "sync"
23         "syscall"
24         "testing"
25         "time"
26 )
27
28 // Gocheck boilerplate
29 func TestCrunchExec(t *testing.T) {
30         TestingT(t)
31 }
32
33 type TestSuite struct{}
34
35 // Gocheck boilerplate
36 var _ = Suite(&TestSuite{})
37
38 type ArvTestClient struct {
39         Total   int64
40         Calls   int
41         Content []arvadosclient.Dict
42         arvados.Container
43         Logs          map[string]*bytes.Buffer
44         WasSetRunning bool
45         sync.Mutex
46 }
47
48 type KeepTestClient struct {
49         Called  bool
50         Content []byte
51 }
52
53 var hwManifest = ". 82ab40c24fc8df01798e57ba66795bb1+841216+Aa124ac75e5168396c73c0a18eda641a4f41791c0@569fa8c3 0:841216:9c31ee32b3d15268a0754e8edc74d4f815ee014b693bc5109058e431dd5caea7.tar\n"
54 var hwPDH = "a45557269dcb65a6b78f9ac061c0850b+120"
55 var hwImageId = "9c31ee32b3d15268a0754e8edc74d4f815ee014b693bc5109058e431dd5caea7"
56
57 var otherManifest = ". 68a84f561b1d1708c6baff5e019a9ab3+46+Ae5d0af96944a3690becb1decdf60cc1c937f556d@5693216f 0:46:md5sum.txt\n"
58 var otherPDH = "a3e8f74c6f101eae01fa08bfb4e49b3a+54"
59
60 var fakeAuthUUID = "zzzzz-gj3su-55pqoyepgi2glem"
61 var fakeAuthToken = "a3ltuwzqcu2u4sc0q7yhpc2w7s00fdcqecg5d6e0u3pfohmbjt"
62
63 type TestDockerClient struct {
64         imageLoaded string
65         logReader   io.ReadCloser
66         logWriter   io.WriteCloser
67         fn          func(t *TestDockerClient)
68         finish      chan dockerclient.WaitResult
69         stop        chan bool
70         cwd         string
71         env         []string
72         api         *ArvTestClient
73 }
74
75 func NewTestDockerClient() *TestDockerClient {
76         t := &TestDockerClient{}
77         t.logReader, t.logWriter = io.Pipe()
78         t.finish = make(chan dockerclient.WaitResult)
79         t.stop = make(chan bool)
80         t.cwd = "/"
81         return t
82 }
83
84 func (t *TestDockerClient) StopContainer(id string, timeout int) error {
85         t.stop <- true
86         return nil
87 }
88
89 func (t *TestDockerClient) InspectImage(id string) (*dockerclient.ImageInfo, error) {
90         if t.imageLoaded == id {
91                 return &dockerclient.ImageInfo{}, nil
92         } else {
93                 return nil, errors.New("")
94         }
95 }
96
97 func (t *TestDockerClient) LoadImage(reader io.Reader) error {
98         _, err := io.Copy(ioutil.Discard, reader)
99         if err != nil {
100                 return err
101         } else {
102                 t.imageLoaded = hwImageId
103                 return nil
104         }
105 }
106
107 func (t *TestDockerClient) CreateContainer(config *dockerclient.ContainerConfig, name string, authConfig *dockerclient.AuthConfig) (string, error) {
108         if config.WorkingDir != "" {
109                 t.cwd = config.WorkingDir
110         }
111         t.env = config.Env
112         return "abcde", nil
113 }
114
115 func (t *TestDockerClient) StartContainer(id string, config *dockerclient.HostConfig) error {
116         if id == "abcde" {
117                 go t.fn(t)
118                 return nil
119         } else {
120                 return errors.New("Invalid container id")
121         }
122 }
123
124 func (t *TestDockerClient) AttachContainer(id string, options *dockerclient.AttachOptions) (io.ReadCloser, error) {
125         return t.logReader, nil
126 }
127
128 func (t *TestDockerClient) Wait(id string) <-chan dockerclient.WaitResult {
129         return t.finish
130 }
131
132 func (*TestDockerClient) RemoveImage(name string, force bool) ([]*dockerclient.ImageDelete, error) {
133         return nil, nil
134 }
135
136 func (client *ArvTestClient) Create(resourceType string,
137         parameters arvadosclient.Dict,
138         output interface{}) error {
139
140         client.Mutex.Lock()
141         defer client.Mutex.Unlock()
142
143         client.Calls++
144         client.Content = append(client.Content, parameters)
145
146         if resourceType == "logs" {
147                 et := parameters["log"].(arvadosclient.Dict)["event_type"].(string)
148                 if client.Logs == nil {
149                         client.Logs = make(map[string]*bytes.Buffer)
150                 }
151                 if client.Logs[et] == nil {
152                         client.Logs[et] = &bytes.Buffer{}
153                 }
154                 client.Logs[et].Write([]byte(parameters["log"].(arvadosclient.Dict)["properties"].(map[string]string)["text"]))
155         }
156
157         if resourceType == "collections" && output != nil {
158                 mt := parameters["collection"].(arvadosclient.Dict)["manifest_text"].(string)
159                 outmap := output.(*arvados.Collection)
160                 outmap.PortableDataHash = fmt.Sprintf("%x+%d", md5.Sum([]byte(mt)), len(mt))
161         }
162
163         return nil
164 }
165
166 func (client *ArvTestClient) Call(method, resourceType, uuid, action string, parameters arvadosclient.Dict, output interface{}) error {
167         switch {
168         case method == "GET" && resourceType == "containers" && action == "auth":
169                 return json.Unmarshal([]byte(`{
170                         "kind": "arvados#api_client_authorization",
171                         "uuid": "`+fakeAuthUUID+`",
172                         "api_token": "`+fakeAuthToken+`"
173                         }`), output)
174         default:
175                 return fmt.Errorf("Not found")
176         }
177 }
178
179 func (client *ArvTestClient) Get(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) error {
180         if resourceType == "collections" {
181                 if uuid == hwPDH {
182                         output.(*arvados.Collection).ManifestText = hwManifest
183                 } else if uuid == otherPDH {
184                         output.(*arvados.Collection).ManifestText = otherManifest
185                 }
186         }
187         if resourceType == "containers" {
188                 (*output.(*arvados.Container)) = client.Container
189         }
190         return nil
191 }
192
193 func (client *ArvTestClient) Update(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) (err error) {
194         client.Mutex.Lock()
195         defer client.Mutex.Unlock()
196         client.Calls++
197         client.Content = append(client.Content, parameters)
198         if resourceType == "containers" {
199                 if parameters["container"].(arvadosclient.Dict)["state"] == "Running" {
200                         client.WasSetRunning = true
201                 }
202         }
203         return nil
204 }
205
206 var discoveryMap = map[string]interface{}{"defaultTrashLifetime": float64(1209600)}
207
208 func (client *ArvTestClient) Discovery(key string) (interface{}, error) {
209         return discoveryMap[key], nil
210 }
211
212 // CalledWith returns the parameters from the first API call whose
213 // parameters match jpath/string. E.g., CalledWith(c, "foo.bar",
214 // "baz") returns parameters with parameters["foo"]["bar"]=="baz". If
215 // no call matches, it returns nil.
216 func (client *ArvTestClient) CalledWith(jpath string, expect interface{}) arvadosclient.Dict {
217 call:
218         for _, content := range client.Content {
219                 var v interface{} = content
220                 for _, k := range strings.Split(jpath, ".") {
221                         if dict, ok := v.(arvadosclient.Dict); !ok {
222                                 continue call
223                         } else {
224                                 v = dict[k]
225                         }
226                 }
227                 if v == expect {
228                         return content
229                 }
230         }
231         return nil
232 }
233
234 func (client *KeepTestClient) PutHB(hash string, buf []byte) (string, int, error) {
235         client.Content = buf
236         return fmt.Sprintf("%s+%d", hash, len(buf)), len(buf), nil
237 }
238
239 type FileWrapper struct {
240         io.ReadCloser
241         len uint64
242 }
243
244 func (fw FileWrapper) Len() uint64 {
245         return fw.len
246 }
247
248 func (fw FileWrapper) Seek(int64, int) (int64, error) {
249         return 0, errors.New("not implemented")
250 }
251
252 func (client *KeepTestClient) ManifestFileReader(m manifest.Manifest, filename string) (keepclient.Reader, error) {
253         if filename == hwImageId+".tar" {
254                 rdr := ioutil.NopCloser(&bytes.Buffer{})
255                 client.Called = true
256                 return FileWrapper{rdr, 1321984}, nil
257         }
258         return nil, nil
259 }
260
261 func (s *TestSuite) TestLoadImage(c *C) {
262         kc := &KeepTestClient{}
263         docker := NewTestDockerClient()
264         cr := NewContainerRunner(&ArvTestClient{}, kc, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
265
266         _, err := cr.Docker.RemoveImage(hwImageId, true)
267
268         _, err = cr.Docker.InspectImage(hwImageId)
269         c.Check(err, NotNil)
270
271         cr.Container.ContainerImage = hwPDH
272
273         // (1) Test loading image from keep
274         c.Check(kc.Called, Equals, false)
275         c.Check(cr.ContainerConfig.Image, Equals, "")
276
277         err = cr.LoadImage()
278
279         c.Check(err, IsNil)
280         defer func() {
281                 cr.Docker.RemoveImage(hwImageId, true)
282         }()
283
284         c.Check(kc.Called, Equals, true)
285         c.Check(cr.ContainerConfig.Image, Equals, hwImageId)
286
287         _, err = cr.Docker.InspectImage(hwImageId)
288         c.Check(err, IsNil)
289
290         // (2) Test using image that's already loaded
291         kc.Called = false
292         cr.ContainerConfig.Image = ""
293
294         err = cr.LoadImage()
295         c.Check(err, IsNil)
296         c.Check(kc.Called, Equals, false)
297         c.Check(cr.ContainerConfig.Image, Equals, hwImageId)
298
299 }
300
301 type ArvErrorTestClient struct{}
302
303 func (ArvErrorTestClient) Create(resourceType string,
304         parameters arvadosclient.Dict,
305         output interface{}) error {
306         return nil
307 }
308
309 func (ArvErrorTestClient) Call(method, resourceType, uuid, action string, parameters arvadosclient.Dict, output interface{}) error {
310         return errors.New("ArvError")
311 }
312
313 func (ArvErrorTestClient) Get(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) error {
314         return errors.New("ArvError")
315 }
316
317 func (ArvErrorTestClient) Update(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) (err error) {
318         return nil
319 }
320
321 func (ArvErrorTestClient) Discovery(key string) (interface{}, error) {
322         return discoveryMap[key], nil
323 }
324
325 type KeepErrorTestClient struct{}
326
327 func (KeepErrorTestClient) PutHB(hash string, buf []byte) (string, int, error) {
328         return "", 0, errors.New("KeepError")
329 }
330
331 func (KeepErrorTestClient) ManifestFileReader(m manifest.Manifest, filename string) (keepclient.Reader, error) {
332         return nil, errors.New("KeepError")
333 }
334
335 type KeepReadErrorTestClient struct{}
336
337 func (KeepReadErrorTestClient) PutHB(hash string, buf []byte) (string, int, error) {
338         return "", 0, nil
339 }
340
341 type ErrorReader struct{}
342
343 func (ErrorReader) Read(p []byte) (n int, err error) {
344         return 0, errors.New("ErrorReader")
345 }
346
347 func (ErrorReader) Close() error {
348         return nil
349 }
350
351 func (ErrorReader) Len() uint64 {
352         return 0
353 }
354
355 func (ErrorReader) Seek(int64, int) (int64, error) {
356         return 0, errors.New("ErrorReader")
357 }
358
359 func (KeepReadErrorTestClient) ManifestFileReader(m manifest.Manifest, filename string) (keepclient.Reader, error) {
360         return ErrorReader{}, nil
361 }
362
363 func (s *TestSuite) TestLoadImageArvError(c *C) {
364         // (1) Arvados error
365         cr := NewContainerRunner(ArvErrorTestClient{}, &KeepTestClient{}, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
366         cr.Container.ContainerImage = hwPDH
367
368         err := cr.LoadImage()
369         c.Check(err.Error(), Equals, "While getting container image collection: ArvError")
370 }
371
372 func (s *TestSuite) TestLoadImageKeepError(c *C) {
373         // (2) Keep error
374         docker := NewTestDockerClient()
375         cr := NewContainerRunner(&ArvTestClient{}, KeepErrorTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
376         cr.Container.ContainerImage = hwPDH
377
378         err := cr.LoadImage()
379         c.Check(err.Error(), Equals, "While creating ManifestFileReader for container image: KeepError")
380 }
381
382 func (s *TestSuite) TestLoadImageCollectionError(c *C) {
383         // (3) Collection doesn't contain image
384         cr := NewContainerRunner(&ArvTestClient{}, KeepErrorTestClient{}, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
385         cr.Container.ContainerImage = otherPDH
386
387         err := cr.LoadImage()
388         c.Check(err.Error(), Equals, "First file in the container image collection does not end in .tar")
389 }
390
391 func (s *TestSuite) TestLoadImageKeepReadError(c *C) {
392         // (4) Collection doesn't contain image
393         docker := NewTestDockerClient()
394         cr := NewContainerRunner(&ArvTestClient{}, KeepReadErrorTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
395         cr.Container.ContainerImage = hwPDH
396
397         err := cr.LoadImage()
398         c.Check(err, NotNil)
399 }
400
401 type ClosableBuffer struct {
402         bytes.Buffer
403 }
404
405 func (*ClosableBuffer) Close() error {
406         return nil
407 }
408
409 type TestLogs struct {
410         Stdout ClosableBuffer
411         Stderr ClosableBuffer
412 }
413
414 func (tl *TestLogs) NewTestLoggingWriter(logstr string) io.WriteCloser {
415         if logstr == "stdout" {
416                 return &tl.Stdout
417         }
418         if logstr == "stderr" {
419                 return &tl.Stderr
420         }
421         return nil
422 }
423
424 func dockerLog(fd byte, msg string) []byte {
425         by := []byte(msg)
426         header := make([]byte, 8+len(by))
427         header[0] = fd
428         header[7] = byte(len(by))
429         copy(header[8:], by)
430         return header
431 }
432
433 func (s *TestSuite) TestRunContainer(c *C) {
434         docker := NewTestDockerClient()
435         docker.fn = func(t *TestDockerClient) {
436                 t.logWriter.Write(dockerLog(1, "Hello world\n"))
437                 t.logWriter.Close()
438                 t.finish <- dockerclient.WaitResult{}
439         }
440         cr := NewContainerRunner(&ArvTestClient{}, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
441
442         var logs TestLogs
443         cr.NewLogWriter = logs.NewTestLoggingWriter
444         cr.Container.ContainerImage = hwPDH
445         cr.Container.Command = []string{"./hw"}
446         err := cr.LoadImage()
447         c.Check(err, IsNil)
448
449         err = cr.CreateContainer()
450         c.Check(err, IsNil)
451
452         err = cr.StartContainer()
453         c.Check(err, IsNil)
454
455         err = cr.WaitFinish()
456         c.Check(err, IsNil)
457
458         c.Check(strings.HasSuffix(logs.Stdout.String(), "Hello world\n"), Equals, true)
459         c.Check(logs.Stderr.String(), Equals, "")
460 }
461
462 func (s *TestSuite) TestCommitLogs(c *C) {
463         api := &ArvTestClient{}
464         kc := &KeepTestClient{}
465         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
466         cr.CrunchLog.Timestamper = (&TestTimestamper{}).Timestamp
467
468         cr.CrunchLog.Print("Hello world!")
469         cr.CrunchLog.Print("Goodbye")
470         cr.finalState = "Complete"
471
472         err := cr.CommitLogs()
473         c.Check(err, IsNil)
474
475         c.Check(api.Calls, Equals, 2)
476         c.Check(api.Content[1]["collection"].(arvadosclient.Dict)["name"], Equals, "logs for zzzzz-zzzzz-zzzzzzzzzzzzzzz")
477         c.Check(api.Content[1]["collection"].(arvadosclient.Dict)["manifest_text"], Equals, ". 744b2e4553123b02fa7b452ec5c18993+123 0:123:crunch-run.txt\n")
478         c.Check(*cr.LogsPDH, Equals, "63da7bdacf08c40f604daad80c261e9a+60")
479 }
480
481 func (s *TestSuite) TestUpdateContainerRunning(c *C) {
482         api := &ArvTestClient{}
483         kc := &KeepTestClient{}
484         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
485
486         err := cr.UpdateContainerRunning()
487         c.Check(err, IsNil)
488
489         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["state"], Equals, "Running")
490 }
491
492 func (s *TestSuite) TestUpdateContainerComplete(c *C) {
493         api := &ArvTestClient{}
494         kc := &KeepTestClient{}
495         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
496
497         cr.LogsPDH = new(string)
498         *cr.LogsPDH = "d3a229d2fe3690c2c3e75a71a153c6a3+60"
499
500         cr.ExitCode = new(int)
501         *cr.ExitCode = 42
502         cr.finalState = "Complete"
503
504         err := cr.UpdateContainerFinal()
505         c.Check(err, IsNil)
506
507         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["log"], Equals, *cr.LogsPDH)
508         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["exit_code"], Equals, *cr.ExitCode)
509         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["state"], Equals, "Complete")
510 }
511
512 func (s *TestSuite) TestUpdateContainerCancelled(c *C) {
513         api := &ArvTestClient{}
514         kc := &KeepTestClient{}
515         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
516         cr.Cancelled = true
517         cr.finalState = "Cancelled"
518
519         err := cr.UpdateContainerFinal()
520         c.Check(err, IsNil)
521
522         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["log"], IsNil)
523         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["exit_code"], IsNil)
524         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["state"], Equals, "Cancelled")
525 }
526
527 // Used by the TestFullRun*() test below to DRY up boilerplate setup to do full
528 // dress rehearsal of the Run() function, starting from a JSON container record.
529 func FullRunHelper(c *C, record string, fn func(t *TestDockerClient)) (api *ArvTestClient, cr *ContainerRunner) {
530         rec := arvados.Container{}
531         err := json.Unmarshal([]byte(record), &rec)
532         c.Check(err, IsNil)
533
534         docker := NewTestDockerClient()
535         docker.fn = fn
536         docker.RemoveImage(hwImageId, true)
537
538         api = &ArvTestClient{Container: rec}
539         docker.api = api
540         cr = NewContainerRunner(api, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
541         cr.statInterval = 100 * time.Millisecond
542         am := &ArvMountCmdLine{}
543         cr.RunArvMount = am.ArvMountTest
544
545         err = cr.Run()
546         c.Check(err, IsNil)
547         c.Check(api.WasSetRunning, Equals, true)
548
549         c.Check(api.Content[api.Calls-1]["container"].(arvadosclient.Dict)["log"], NotNil)
550
551         if err != nil {
552                 for k, v := range api.Logs {
553                         c.Log(k)
554                         c.Log(v.String())
555                 }
556         }
557
558         return
559 }
560
561 func (s *TestSuite) TestFullRunHello(c *C) {
562         api, _ := FullRunHelper(c, `{
563     "command": ["echo", "hello world"],
564     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
565     "cwd": ".",
566     "environment": {},
567     "mounts": {"/tmp": {"kind": "tmp"} },
568     "output_path": "/tmp",
569     "priority": 1,
570     "runtime_constraints": {}
571 }`, func(t *TestDockerClient) {
572                 t.logWriter.Write(dockerLog(1, "hello world\n"))
573                 t.logWriter.Close()
574                 t.finish <- dockerclient.WaitResult{}
575         })
576
577         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
578         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
579         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "hello world\n"), Equals, true)
580
581 }
582
583 func (s *TestSuite) TestCrunchstat(c *C) {
584         api, _ := FullRunHelper(c, `{
585                 "command": ["sleep", "1"],
586                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
587                 "cwd": ".",
588                 "environment": {},
589                 "mounts": {"/tmp": {"kind": "tmp"} },
590                 "output_path": "/tmp",
591                 "priority": 1,
592                 "runtime_constraints": {}
593         }`, func(t *TestDockerClient) {
594                 time.Sleep(time.Second)
595                 t.logWriter.Close()
596                 t.finish <- dockerclient.WaitResult{}
597         })
598
599         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
600         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
601
602         // We didn't actually start a container, so crunchstat didn't
603         // find accounting files and therefore didn't log any stats.
604         // It should have logged a "can't find accounting files"
605         // message after one poll interval, though, so we can confirm
606         // it's alive:
607         c.Assert(api.Logs["crunchstat"], NotNil)
608         c.Check(api.Logs["crunchstat"].String(), Matches, `(?ms).*cgroup stats files have not appeared after 100ms.*`)
609
610         // The "files never appeared" log assures us that we called
611         // (*crunchstat.Reporter)Stop(), and that we set it up with
612         // the correct container ID "abcde":
613         c.Check(api.Logs["crunchstat"].String(), Matches, `(?ms).*cgroup stats files never appeared for abcde\n`)
614 }
615
616 func (s *TestSuite) TestFullRunStderr(c *C) {
617         api, _ := FullRunHelper(c, `{
618     "command": ["/bin/sh", "-c", "echo hello ; echo world 1>&2 ; exit 1"],
619     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
620     "cwd": ".",
621     "environment": {},
622     "mounts": {"/tmp": {"kind": "tmp"} },
623     "output_path": "/tmp",
624     "priority": 1,
625     "runtime_constraints": {}
626 }`, func(t *TestDockerClient) {
627                 t.logWriter.Write(dockerLog(1, "hello\n"))
628                 t.logWriter.Write(dockerLog(2, "world\n"))
629                 t.logWriter.Close()
630                 t.finish <- dockerclient.WaitResult{ExitCode: 1}
631         })
632
633         final := api.CalledWith("container.state", "Complete")
634         c.Assert(final, NotNil)
635         c.Check(final["container"].(arvadosclient.Dict)["exit_code"], Equals, 1)
636         c.Check(final["container"].(arvadosclient.Dict)["log"], NotNil)
637
638         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "hello\n"), Equals, true)
639         c.Check(strings.HasSuffix(api.Logs["stderr"].String(), "world\n"), Equals, true)
640 }
641
642 func (s *TestSuite) TestFullRunDefaultCwd(c *C) {
643         api, _ := FullRunHelper(c, `{
644     "command": ["pwd"],
645     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
646     "cwd": ".",
647     "environment": {},
648     "mounts": {"/tmp": {"kind": "tmp"} },
649     "output_path": "/tmp",
650     "priority": 1,
651     "runtime_constraints": {}
652 }`, func(t *TestDockerClient) {
653                 t.logWriter.Write(dockerLog(1, t.cwd+"\n"))
654                 t.logWriter.Close()
655                 t.finish <- dockerclient.WaitResult{ExitCode: 0}
656         })
657
658         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
659         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
660         c.Log(api.Logs["stdout"])
661         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "/\n"), Equals, true)
662 }
663
664 func (s *TestSuite) TestFullRunSetCwd(c *C) {
665         api, _ := FullRunHelper(c, `{
666     "command": ["pwd"],
667     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
668     "cwd": "/bin",
669     "environment": {},
670     "mounts": {"/tmp": {"kind": "tmp"} },
671     "output_path": "/tmp",
672     "priority": 1,
673     "runtime_constraints": {}
674 }`, func(t *TestDockerClient) {
675                 t.logWriter.Write(dockerLog(1, t.cwd+"\n"))
676                 t.logWriter.Close()
677                 t.finish <- dockerclient.WaitResult{ExitCode: 0}
678         })
679
680         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
681         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
682         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "/bin\n"), Equals, true)
683 }
684
685 func (s *TestSuite) TestCancel(c *C) {
686         record := `{
687     "command": ["/bin/sh", "-c", "echo foo && sleep 30 && echo bar"],
688     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
689     "cwd": ".",
690     "environment": {},
691     "mounts": {"/tmp": {"kind": "tmp"} },
692     "output_path": "/tmp",
693     "priority": 1,
694     "runtime_constraints": {}
695 }`
696
697         rec := arvados.Container{}
698         err := json.Unmarshal([]byte(record), &rec)
699         c.Check(err, IsNil)
700
701         docker := NewTestDockerClient()
702         docker.fn = func(t *TestDockerClient) {
703                 <-t.stop
704                 t.logWriter.Write(dockerLog(1, "foo\n"))
705                 t.logWriter.Close()
706                 t.finish <- dockerclient.WaitResult{ExitCode: 0}
707         }
708         docker.RemoveImage(hwImageId, true)
709
710         api := &ArvTestClient{Container: rec}
711         cr := NewContainerRunner(api, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
712         am := &ArvMountCmdLine{}
713         cr.RunArvMount = am.ArvMountTest
714
715         go func() {
716                 for cr.ContainerID == "" {
717                         time.Sleep(time.Millisecond)
718                 }
719                 cr.SigChan <- syscall.SIGINT
720         }()
721
722         err = cr.Run()
723
724         c.Check(err, IsNil)
725         if err != nil {
726                 for k, v := range api.Logs {
727                         c.Log(k)
728                         c.Log(v.String())
729                 }
730         }
731
732         c.Check(api.CalledWith("container.log", nil), NotNil)
733         c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
734         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "foo\n"), Equals, true)
735
736 }
737
738 func (s *TestSuite) TestFullRunSetEnv(c *C) {
739         api, _ := FullRunHelper(c, `{
740     "command": ["/bin/sh", "-c", "echo $FROBIZ"],
741     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
742     "cwd": "/bin",
743     "environment": {"FROBIZ": "bilbo"},
744     "mounts": {"/tmp": {"kind": "tmp"} },
745     "output_path": "/tmp",
746     "priority": 1,
747     "runtime_constraints": {}
748 }`, func(t *TestDockerClient) {
749                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
750                 t.logWriter.Close()
751                 t.finish <- dockerclient.WaitResult{ExitCode: 0}
752         })
753
754         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
755         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
756         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "bilbo\n"), Equals, true)
757 }
758
759 type ArvMountCmdLine struct {
760         Cmd   []string
761         token string
762 }
763
764 func (am *ArvMountCmdLine) ArvMountTest(c []string, token string) (*exec.Cmd, error) {
765         am.Cmd = c
766         am.token = token
767         return nil, nil
768 }
769
770 func stubCert(temp string) string {
771         path := temp + "/ca-certificates.crt"
772         crt, _ := os.Create(path)
773         crt.Close()
774         arvadosclient.CertFiles = []string{path}
775         return path
776 }
777
778 func (s *TestSuite) TestSetupMounts(c *C) {
779         api := &ArvTestClient{}
780         kc := &KeepTestClient{}
781         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
782         am := &ArvMountCmdLine{}
783         cr.RunArvMount = am.ArvMountTest
784
785         realTemp, err := ioutil.TempDir("", "crunchrun_test1-")
786         c.Assert(err, IsNil)
787         certTemp, err := ioutil.TempDir("", "crunchrun_test2-")
788         c.Assert(err, IsNil)
789         stubCertPath := stubCert(certTemp)
790
791         defer os.RemoveAll(realTemp)
792         defer os.RemoveAll(certTemp)
793
794         i := 0
795         cr.MkTempDir = func(_ string, prefix string) (string, error) {
796                 i++
797                 d := fmt.Sprintf("%s/%s%d", realTemp, prefix, i)
798                 err := os.Mkdir(d, os.ModePerm)
799                 if err != nil && strings.Contains(err.Error(), ": file exists") {
800                         // Test case must have pre-populated the tempdir
801                         err = nil
802                 }
803                 return d, err
804         }
805
806         checkEmpty := func() {
807                 filepath.Walk(realTemp, func(path string, _ os.FileInfo, err error) error {
808                         c.Check(path, Equals, realTemp)
809                         c.Check(err, IsNil)
810                         return nil
811                 })
812         }
813
814         {
815                 i = 0
816                 cr.Container.Mounts = make(map[string]arvados.Mount)
817                 cr.Container.Mounts["/tmp"] = arvados.Mount{Kind: "tmp"}
818                 cr.OutputPath = "/tmp"
819
820                 err := cr.SetupMounts()
821                 c.Check(err, IsNil)
822                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
823                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp"})
824                 cr.CleanupDirs()
825                 checkEmpty()
826         }
827
828         {
829                 i = 0
830                 cr.Container.Mounts = make(map[string]arvados.Mount)
831                 cr.Container.Mounts["/tmp"] = arvados.Mount{Kind: "tmp"}
832                 cr.OutputPath = "/tmp"
833
834                 apiflag := true
835                 cr.Container.RuntimeConstraints.API = &apiflag
836
837                 err := cr.SetupMounts()
838                 c.Check(err, IsNil)
839                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
840                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp", stubCertPath + ":/etc/arvados/ca-certificates.crt:ro"})
841                 cr.CleanupDirs()
842                 checkEmpty()
843
844                 apiflag = false
845         }
846
847         {
848                 i = 0
849                 cr.Container.Mounts = map[string]arvados.Mount{
850                         "/keeptmp": {Kind: "collection", Writable: true},
851                 }
852                 cr.OutputPath = "/keeptmp"
853
854                 os.MkdirAll(realTemp+"/keep1/tmp0", os.ModePerm)
855
856                 err := cr.SetupMounts()
857                 c.Check(err, IsNil)
858                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
859                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/tmp0:/keeptmp"})
860                 cr.CleanupDirs()
861                 checkEmpty()
862         }
863
864         {
865                 i = 0
866                 cr.Container.Mounts = map[string]arvados.Mount{
867                         "/keepinp": {Kind: "collection", PortableDataHash: "59389a8f9ee9d399be35462a0f92541c+53"},
868                         "/keepout": {Kind: "collection", Writable: true},
869                 }
870                 cr.OutputPath = "/keepout"
871
872                 os.MkdirAll(realTemp+"/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53", os.ModePerm)
873                 os.MkdirAll(realTemp+"/keep1/tmp0", os.ModePerm)
874
875                 err := cr.SetupMounts()
876                 c.Check(err, IsNil)
877                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
878                 sort.StringSlice(cr.Binds).Sort()
879                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53:/keepinp:ro",
880                         realTemp + "/keep1/tmp0:/keepout"})
881                 cr.CleanupDirs()
882                 checkEmpty()
883         }
884
885         {
886                 i = 0
887                 cr.Container.RuntimeConstraints.KeepCacheRAM = 512
888                 cr.Container.Mounts = map[string]arvados.Mount{
889                         "/keepinp": {Kind: "collection", PortableDataHash: "59389a8f9ee9d399be35462a0f92541c+53"},
890                         "/keepout": {Kind: "collection", Writable: true},
891                 }
892                 cr.OutputPath = "/keepout"
893
894                 os.MkdirAll(realTemp+"/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53", os.ModePerm)
895                 os.MkdirAll(realTemp+"/keep1/tmp0", os.ModePerm)
896
897                 err := cr.SetupMounts()
898                 c.Check(err, IsNil)
899                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--file-cache", "512", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
900                 sort.StringSlice(cr.Binds).Sort()
901                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53:/keepinp:ro",
902                         realTemp + "/keep1/tmp0:/keepout"})
903                 cr.CleanupDirs()
904                 checkEmpty()
905         }
906
907         for _, test := range []struct {
908                 in  interface{}
909                 out string
910         }{
911                 {in: "foo", out: `"foo"`},
912                 {in: nil, out: `null`},
913                 {in: map[string]int{"foo": 123}, out: `{"foo":123}`},
914         } {
915                 i = 0
916                 cr.Container.Mounts = map[string]arvados.Mount{
917                         "/mnt/test.json": {Kind: "json", Content: test.in},
918                 }
919                 err := cr.SetupMounts()
920                 c.Check(err, IsNil)
921                 sort.StringSlice(cr.Binds).Sort()
922                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2/mountdata.json:/mnt/test.json:ro"})
923                 content, err := ioutil.ReadFile(realTemp + "/2/mountdata.json")
924                 c.Check(err, IsNil)
925                 c.Check(content, DeepEquals, []byte(test.out))
926                 cr.CleanupDirs()
927                 checkEmpty()
928         }
929 }
930
931 func (s *TestSuite) TestStdout(c *C) {
932         helperRecord := `{
933                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
934                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
935                 "cwd": "/bin",
936                 "environment": {"FROBIZ": "bilbo"},
937                 "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "file", "path": "/tmp/a/b/c.out"} },
938                 "output_path": "/tmp",
939                 "priority": 1,
940                 "runtime_constraints": {}
941         }`
942
943         api, _ := FullRunHelper(c, helperRecord, func(t *TestDockerClient) {
944                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
945                 t.logWriter.Close()
946                 t.finish <- dockerclient.WaitResult{ExitCode: 0}
947         })
948
949         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
950         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
951         c.Check(api.CalledWith("collection.manifest_text", "./a/b 307372fa8fd5c146b22ae7a45b49bc31+6 0:6:c.out\n"), NotNil)
952 }
953
954 // Used by the TestStdoutWithWrongPath*()
955 func StdoutErrorRunHelper(c *C, record string, fn func(t *TestDockerClient)) (api *ArvTestClient, cr *ContainerRunner, err error) {
956         rec := arvados.Container{}
957         err = json.Unmarshal([]byte(record), &rec)
958         c.Check(err, IsNil)
959
960         docker := NewTestDockerClient()
961         docker.fn = fn
962         docker.RemoveImage(hwImageId, true)
963
964         api = &ArvTestClient{Container: rec}
965         cr = NewContainerRunner(api, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
966         am := &ArvMountCmdLine{}
967         cr.RunArvMount = am.ArvMountTest
968
969         err = cr.Run()
970         return
971 }
972
973 func (s *TestSuite) TestStdoutWithWrongPath(c *C) {
974         _, _, err := StdoutErrorRunHelper(c, `{
975     "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "file", "path":"/tmpa.out"} },
976     "output_path": "/tmp"
977 }`, func(t *TestDockerClient) {})
978
979         c.Check(err, NotNil)
980         c.Check(strings.Contains(err.Error(), "Stdout path does not start with OutputPath"), Equals, true)
981 }
982
983 func (s *TestSuite) TestStdoutWithWrongKindTmp(c *C) {
984         _, _, err := StdoutErrorRunHelper(c, `{
985     "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "tmp", "path":"/tmp/a.out"} },
986     "output_path": "/tmp"
987 }`, func(t *TestDockerClient) {})
988
989         c.Check(err, NotNil)
990         c.Check(strings.Contains(err.Error(), "Unsupported mount kind 'tmp' for stdout"), Equals, true)
991 }
992
993 func (s *TestSuite) TestStdoutWithWrongKindCollection(c *C) {
994         _, _, err := StdoutErrorRunHelper(c, `{
995     "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "collection", "path":"/tmp/a.out"} },
996     "output_path": "/tmp"
997 }`, func(t *TestDockerClient) {})
998
999         c.Check(err, NotNil)
1000         c.Check(strings.Contains(err.Error(), "Unsupported mount kind 'collection' for stdout"), Equals, true)
1001 }
1002
1003 func (s *TestSuite) TestFullRunWithAPI(c *C) {
1004         os.Setenv("ARVADOS_API_HOST", "test.arvados.org")
1005         defer os.Unsetenv("ARVADOS_API_HOST")
1006         api, _ := FullRunHelper(c, `{
1007     "command": ["/bin/sh", "-c", "echo $ARVADOS_API_HOST"],
1008     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1009     "cwd": "/bin",
1010     "environment": {},
1011     "mounts": {"/tmp": {"kind": "tmp"} },
1012     "output_path": "/tmp",
1013     "priority": 1,
1014     "runtime_constraints": {"API": true}
1015 }`, func(t *TestDockerClient) {
1016                 t.logWriter.Write(dockerLog(1, t.env[1][17:]+"\n"))
1017                 t.logWriter.Close()
1018                 t.finish <- dockerclient.WaitResult{ExitCode: 0}
1019         })
1020
1021         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1022         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1023         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "test.arvados.org\n"), Equals, true)
1024         c.Check(api.CalledWith("container.output", "d41d8cd98f00b204e9800998ecf8427e+0"), NotNil)
1025 }
1026
1027 func (s *TestSuite) TestFullRunSetOutput(c *C) {
1028         os.Setenv("ARVADOS_API_HOST", "test.arvados.org")
1029         defer os.Unsetenv("ARVADOS_API_HOST")
1030         api, _ := FullRunHelper(c, `{
1031     "command": ["/bin/sh", "-c", "echo $ARVADOS_API_HOST"],
1032     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1033     "cwd": "/bin",
1034     "environment": {},
1035     "mounts": {"/tmp": {"kind": "tmp"} },
1036     "output_path": "/tmp",
1037     "priority": 1,
1038     "runtime_constraints": {"API": true}
1039 }`, func(t *TestDockerClient) {
1040                 t.api.Container.Output = "d4ab34d3d4f8a72f5c4973051ae69fab+122"
1041                 t.logWriter.Close()
1042                 t.finish <- dockerclient.WaitResult{ExitCode: 0}
1043         })
1044
1045         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1046         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1047         c.Check(api.CalledWith("container.output", "d4ab34d3d4f8a72f5c4973051ae69fab+122"), NotNil)
1048 }