8186: Add EBS storage if necessary so there is sufficient scratch space.
[arvados.git] / services / crunch-run / crunchrun_test.go
1 package main
2
3 import (
4         "bufio"
5         "bytes"
6         "context"
7         "crypto/md5"
8         "encoding/json"
9         "errors"
10         "fmt"
11         "io"
12         "io/ioutil"
13         "net"
14         "os"
15         "os/exec"
16         "path/filepath"
17         "runtime/pprof"
18         "sort"
19         "strings"
20         "sync"
21         "syscall"
22         "testing"
23         "time"
24
25         "git.curoverse.com/arvados.git/sdk/go/arvados"
26         "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
27         "git.curoverse.com/arvados.git/sdk/go/keepclient"
28         "git.curoverse.com/arvados.git/sdk/go/manifest"
29
30         dockertypes "github.com/docker/docker/api/types"
31         dockercontainer "github.com/docker/docker/api/types/container"
32         dockernetwork "github.com/docker/docker/api/types/network"
33         . "gopkg.in/check.v1"
34 )
35
36 // Gocheck boilerplate
37 func TestCrunchExec(t *testing.T) {
38         TestingT(t)
39 }
40
41 type TestSuite struct{}
42
43 // Gocheck boilerplate
44 var _ = Suite(&TestSuite{})
45
46 type ArvTestClient struct {
47         Total   int64
48         Calls   int
49         Content []arvadosclient.Dict
50         arvados.Container
51         Logs map[string]*bytes.Buffer
52         sync.Mutex
53         WasSetRunning bool
54 }
55
56 type KeepTestClient struct {
57         Called  bool
58         Content []byte
59 }
60
61 var hwManifest = ". 82ab40c24fc8df01798e57ba66795bb1+841216+Aa124ac75e5168396c73c0a18eda641a4f41791c0@569fa8c3 0:841216:9c31ee32b3d15268a0754e8edc74d4f815ee014b693bc5109058e431dd5caea7.tar\n"
62 var hwPDH = "a45557269dcb65a6b78f9ac061c0850b+120"
63 var hwImageId = "9c31ee32b3d15268a0754e8edc74d4f815ee014b693bc5109058e431dd5caea7"
64
65 var otherManifest = ". 68a84f561b1d1708c6baff5e019a9ab3+46+Ae5d0af96944a3690becb1decdf60cc1c937f556d@5693216f 0:46:md5sum.txt\n"
66 var otherPDH = "a3e8f74c6f101eae01fa08bfb4e49b3a+54"
67
68 var normalizedManifestWithSubdirs = `. 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0abcdefgh11234567890@569fa8c3 0:9:file1_in_main.txt 9:18:file2_in_main.txt 0:27:zzzzz-8i9sb-bcdefghijkdhvnk.log.txt
69 ./subdir1 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396cabcdefghij6419876543234@569fa8c4 0:9:file1_in_subdir1.txt 9:18:file2_in_subdir1.txt
70 ./subdir1/subdir2 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0bcdefghijk544332211@569fa8c5 0:9:file1_in_subdir2.txt 9:18:file2_in_subdir2.txt
71 `
72
73 var normalizedWithSubdirsPDH = "a0def87f80dd594d4675809e83bd4f15+367"
74
75 var denormalizedManifestWithSubdirs = ". 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0abcdefgh11234567890@569fa8c3 0:9:file1_in_main.txt 9:18:file2_in_main.txt 0:27:zzzzz-8i9sb-bcdefghijkdhvnk.log.txt 0:10:subdir1/file1_in_subdir1.txt 10:17:subdir1/file2_in_subdir1.txt\n"
76 var denormalizedWithSubdirsPDH = "b0def87f80dd594d4675809e83bd4f15+367"
77
78 var fakeAuthUUID = "zzzzz-gj3su-55pqoyepgi2glem"
79 var fakeAuthToken = "a3ltuwzqcu2u4sc0q7yhpc2w7s00fdcqecg5d6e0u3pfohmbjt"
80
81 type TestDockerClient struct {
82         imageLoaded string
83         logReader   io.ReadCloser
84         logWriter   io.WriteCloser
85         fn          func(t *TestDockerClient)
86         finish      int
87         stop        chan bool
88         cwd         string
89         env         []string
90         api         *ArvTestClient
91         realTemp    string
92 }
93
94 func NewTestDockerClient(exitCode int) *TestDockerClient {
95         t := &TestDockerClient{}
96         t.logReader, t.logWriter = io.Pipe()
97         t.finish = exitCode
98         t.stop = make(chan bool)
99         t.cwd = "/"
100         return t
101 }
102
103 type MockConn struct {
104         net.Conn
105 }
106
107 func (m *MockConn) Write(b []byte) (int, error) {
108         return len(b), nil
109 }
110
111 func NewMockConn() *MockConn {
112         c := &MockConn{}
113         return c
114 }
115
116 func (t *TestDockerClient) ContainerAttach(ctx context.Context, container string, options dockertypes.ContainerAttachOptions) (dockertypes.HijackedResponse, error) {
117         return dockertypes.HijackedResponse{Conn: NewMockConn(), Reader: bufio.NewReader(t.logReader)}, nil
118 }
119
120 func (t *TestDockerClient) ContainerCreate(ctx context.Context, config *dockercontainer.Config, hostConfig *dockercontainer.HostConfig, networkingConfig *dockernetwork.NetworkingConfig, containerName string) (dockercontainer.ContainerCreateCreatedBody, error) {
121         if config.WorkingDir != "" {
122                 t.cwd = config.WorkingDir
123         }
124         t.env = config.Env
125         return dockercontainer.ContainerCreateCreatedBody{ID: "abcde"}, nil
126 }
127
128 func (t *TestDockerClient) ContainerStart(ctx context.Context, container string, options dockertypes.ContainerStartOptions) error {
129         if container == "abcde" {
130                 go t.fn(t)
131                 return nil
132         } else {
133                 return errors.New("Invalid container id")
134         }
135 }
136
137 func (t *TestDockerClient) ContainerStop(ctx context.Context, container string, timeout *time.Duration) error {
138         t.stop <- true
139         return nil
140 }
141
142 func (t *TestDockerClient) ContainerWait(ctx context.Context, container string, condition dockercontainer.WaitCondition) (<-chan dockercontainer.ContainerWaitOKBody, <-chan error) {
143         body := make(chan dockercontainer.ContainerWaitOKBody)
144         err := make(chan error)
145         go func() {
146                 body <- dockercontainer.ContainerWaitOKBody{StatusCode: int64(t.finish)}
147                 close(body)
148                 close(err)
149         }()
150         return body, err
151 }
152
153 func (t *TestDockerClient) ImageInspectWithRaw(ctx context.Context, image string) (dockertypes.ImageInspect, []byte, error) {
154         if t.imageLoaded == image {
155                 return dockertypes.ImageInspect{}, nil, nil
156         } else {
157                 return dockertypes.ImageInspect{}, nil, errors.New("")
158         }
159 }
160
161 func (t *TestDockerClient) ImageLoad(ctx context.Context, input io.Reader, quiet bool) (dockertypes.ImageLoadResponse, error) {
162         _, err := io.Copy(ioutil.Discard, input)
163         if err != nil {
164                 return dockertypes.ImageLoadResponse{}, err
165         } else {
166                 t.imageLoaded = hwImageId
167                 return dockertypes.ImageLoadResponse{Body: ioutil.NopCloser(input)}, nil
168         }
169 }
170
171 func (*TestDockerClient) ImageRemove(ctx context.Context, image string, options dockertypes.ImageRemoveOptions) ([]dockertypes.ImageDeleteResponseItem, error) {
172         return nil, nil
173 }
174
175 func (client *ArvTestClient) Create(resourceType string,
176         parameters arvadosclient.Dict,
177         output interface{}) error {
178
179         client.Mutex.Lock()
180         defer client.Mutex.Unlock()
181
182         client.Calls++
183         client.Content = append(client.Content, parameters)
184
185         if resourceType == "logs" {
186                 et := parameters["log"].(arvadosclient.Dict)["event_type"].(string)
187                 if client.Logs == nil {
188                         client.Logs = make(map[string]*bytes.Buffer)
189                 }
190                 if client.Logs[et] == nil {
191                         client.Logs[et] = &bytes.Buffer{}
192                 }
193                 client.Logs[et].Write([]byte(parameters["log"].(arvadosclient.Dict)["properties"].(map[string]string)["text"]))
194         }
195
196         if resourceType == "collections" && output != nil {
197                 mt := parameters["collection"].(arvadosclient.Dict)["manifest_text"].(string)
198                 outmap := output.(*arvados.Collection)
199                 outmap.PortableDataHash = fmt.Sprintf("%x+%d", md5.Sum([]byte(mt)), len(mt))
200         }
201
202         return nil
203 }
204
205 func (client *ArvTestClient) Call(method, resourceType, uuid, action string, parameters arvadosclient.Dict, output interface{}) error {
206         switch {
207         case method == "GET" && resourceType == "containers" && action == "auth":
208                 return json.Unmarshal([]byte(`{
209                         "kind": "arvados#api_client_authorization",
210                         "uuid": "`+fakeAuthUUID+`",
211                         "api_token": "`+fakeAuthToken+`"
212                         }`), output)
213         default:
214                 return fmt.Errorf("Not found")
215         }
216 }
217
218 func (client *ArvTestClient) CallRaw(method, resourceType, uuid, action string,
219         parameters arvadosclient.Dict) (reader io.ReadCloser, err error) {
220         j := []byte(`{
221                 "command": ["sleep", "1"],
222                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
223                 "cwd": ".",
224                 "environment": {},
225                 "mounts": {"/tmp": {"kind": "tmp"} },
226                 "output_path": "/tmp",
227                 "priority": 1,
228                 "runtime_constraints": {}
229         }`)
230         return ioutil.NopCloser(bytes.NewReader(j)), nil
231 }
232
233 func (client *ArvTestClient) Get(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) error {
234         if resourceType == "collections" {
235                 if uuid == hwPDH {
236                         output.(*arvados.Collection).ManifestText = hwManifest
237                 } else if uuid == otherPDH {
238                         output.(*arvados.Collection).ManifestText = otherManifest
239                 } else if uuid == normalizedWithSubdirsPDH {
240                         output.(*arvados.Collection).ManifestText = normalizedManifestWithSubdirs
241                 } else if uuid == denormalizedWithSubdirsPDH {
242                         output.(*arvados.Collection).ManifestText = denormalizedManifestWithSubdirs
243                 }
244         }
245         if resourceType == "containers" {
246                 (*output.(*arvados.Container)) = client.Container
247         }
248         return nil
249 }
250
251 func (client *ArvTestClient) Update(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) (err error) {
252         client.Mutex.Lock()
253         defer client.Mutex.Unlock()
254         client.Calls++
255         client.Content = append(client.Content, parameters)
256         if resourceType == "containers" {
257                 if parameters["container"].(arvadosclient.Dict)["state"] == "Running" {
258                         client.WasSetRunning = true
259                 }
260         }
261         return nil
262 }
263
264 var discoveryMap = map[string]interface{}{
265         "defaultTrashLifetime":               float64(1209600),
266         "crunchLimitLogBytesPerJob":          float64(67108864),
267         "crunchLogThrottleBytes":             float64(65536),
268         "crunchLogThrottlePeriod":            float64(60),
269         "crunchLogThrottleLines":             float64(1024),
270         "crunchLogPartialLineThrottlePeriod": float64(5),
271         "crunchLogBytesPerEvent":             float64(4096),
272         "crunchLogSecondsBetweenEvents":      float64(1),
273 }
274
275 func (client *ArvTestClient) Discovery(key string) (interface{}, error) {
276         return discoveryMap[key], nil
277 }
278
279 // CalledWith returns the parameters from the first API call whose
280 // parameters match jpath/string. E.g., CalledWith(c, "foo.bar",
281 // "baz") returns parameters with parameters["foo"]["bar"]=="baz". If
282 // no call matches, it returns nil.
283 func (client *ArvTestClient) CalledWith(jpath string, expect interface{}) arvadosclient.Dict {
284 call:
285         for _, content := range client.Content {
286                 var v interface{} = content
287                 for _, k := range strings.Split(jpath, ".") {
288                         if dict, ok := v.(arvadosclient.Dict); !ok {
289                                 continue call
290                         } else {
291                                 v = dict[k]
292                         }
293                 }
294                 if v == expect {
295                         return content
296                 }
297         }
298         return nil
299 }
300
301 func (client *KeepTestClient) PutHB(hash string, buf []byte) (string, int, error) {
302         client.Content = buf
303         return fmt.Sprintf("%s+%d", hash, len(buf)), len(buf), nil
304 }
305
306 type FileWrapper struct {
307         io.ReadCloser
308         len uint64
309 }
310
311 func (fw FileWrapper) Len() uint64 {
312         return fw.len
313 }
314
315 func (fw FileWrapper) Seek(int64, int) (int64, error) {
316         return 0, errors.New("not implemented")
317 }
318
319 func (client *KeepTestClient) ManifestFileReader(m manifest.Manifest, filename string) (keepclient.Reader, error) {
320         if filename == hwImageId+".tar" {
321                 rdr := ioutil.NopCloser(&bytes.Buffer{})
322                 client.Called = true
323                 return FileWrapper{rdr, 1321984}, nil
324         } else if filename == "/file1_in_main.txt" {
325                 rdr := ioutil.NopCloser(strings.NewReader("foo"))
326                 client.Called = true
327                 return FileWrapper{rdr, 3}, nil
328         }
329         return nil, nil
330 }
331
332 func (s *TestSuite) TestLoadImage(c *C) {
333         kc := &KeepTestClient{}
334         docker := NewTestDockerClient(0)
335         cr := NewContainerRunner(&ArvTestClient{}, kc, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
336
337         _, err := cr.Docker.ImageRemove(nil, hwImageId, dockertypes.ImageRemoveOptions{})
338
339         _, _, err = cr.Docker.ImageInspectWithRaw(nil, hwImageId)
340         c.Check(err, NotNil)
341
342         cr.Container.ContainerImage = hwPDH
343
344         // (1) Test loading image from keep
345         c.Check(kc.Called, Equals, false)
346         c.Check(cr.ContainerConfig.Image, Equals, "")
347
348         err = cr.LoadImage()
349
350         c.Check(err, IsNil)
351         defer func() {
352                 cr.Docker.ImageRemove(nil, hwImageId, dockertypes.ImageRemoveOptions{})
353         }()
354
355         c.Check(kc.Called, Equals, true)
356         c.Check(cr.ContainerConfig.Image, Equals, hwImageId)
357
358         _, _, err = cr.Docker.ImageInspectWithRaw(nil, hwImageId)
359         c.Check(err, IsNil)
360
361         // (2) Test using image that's already loaded
362         kc.Called = false
363         cr.ContainerConfig.Image = ""
364
365         err = cr.LoadImage()
366         c.Check(err, IsNil)
367         c.Check(kc.Called, Equals, false)
368         c.Check(cr.ContainerConfig.Image, Equals, hwImageId)
369
370 }
371
372 type ArvErrorTestClient struct{}
373
374 func (ArvErrorTestClient) Create(resourceType string,
375         parameters arvadosclient.Dict,
376         output interface{}) error {
377         return nil
378 }
379
380 func (ArvErrorTestClient) Call(method, resourceType, uuid, action string, parameters arvadosclient.Dict, output interface{}) error {
381         return errors.New("ArvError")
382 }
383
384 func (ArvErrorTestClient) CallRaw(method, resourceType, uuid, action string,
385         parameters arvadosclient.Dict) (reader io.ReadCloser, err error) {
386         return nil, errors.New("ArvError")
387 }
388
389 func (ArvErrorTestClient) Get(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) error {
390         return errors.New("ArvError")
391 }
392
393 func (ArvErrorTestClient) Update(resourceType string, uuid string, parameters arvadosclient.Dict, output interface{}) (err error) {
394         return nil
395 }
396
397 func (ArvErrorTestClient) Discovery(key string) (interface{}, error) {
398         return discoveryMap[key], nil
399 }
400
401 type KeepErrorTestClient struct{}
402
403 func (KeepErrorTestClient) PutHB(hash string, buf []byte) (string, int, error) {
404         return "", 0, errors.New("KeepError")
405 }
406
407 func (KeepErrorTestClient) ManifestFileReader(m manifest.Manifest, filename string) (keepclient.Reader, error) {
408         return nil, errors.New("KeepError")
409 }
410
411 type KeepReadErrorTestClient struct{}
412
413 func (KeepReadErrorTestClient) PutHB(hash string, buf []byte) (string, int, error) {
414         return "", 0, nil
415 }
416
417 type ErrorReader struct{}
418
419 func (ErrorReader) Read(p []byte) (n int, err error) {
420         return 0, errors.New("ErrorReader")
421 }
422
423 func (ErrorReader) Close() error {
424         return nil
425 }
426
427 func (ErrorReader) Len() uint64 {
428         return 0
429 }
430
431 func (ErrorReader) Seek(int64, int) (int64, error) {
432         return 0, errors.New("ErrorReader")
433 }
434
435 func (KeepReadErrorTestClient) ManifestFileReader(m manifest.Manifest, filename string) (keepclient.Reader, error) {
436         return ErrorReader{}, nil
437 }
438
439 func (s *TestSuite) TestLoadImageArvError(c *C) {
440         // (1) Arvados error
441         cr := NewContainerRunner(ArvErrorTestClient{}, &KeepTestClient{}, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
442         cr.Container.ContainerImage = hwPDH
443
444         err := cr.LoadImage()
445         c.Check(err.Error(), Equals, "While getting container image collection: ArvError")
446 }
447
448 func (s *TestSuite) TestLoadImageKeepError(c *C) {
449         // (2) Keep error
450         docker := NewTestDockerClient(0)
451         cr := NewContainerRunner(&ArvTestClient{}, KeepErrorTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
452         cr.Container.ContainerImage = hwPDH
453
454         err := cr.LoadImage()
455         c.Check(err.Error(), Equals, "While creating ManifestFileReader for container image: KeepError")
456 }
457
458 func (s *TestSuite) TestLoadImageCollectionError(c *C) {
459         // (3) Collection doesn't contain image
460         cr := NewContainerRunner(&ArvTestClient{}, KeepErrorTestClient{}, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
461         cr.Container.ContainerImage = otherPDH
462
463         err := cr.LoadImage()
464         c.Check(err.Error(), Equals, "First file in the container image collection does not end in .tar")
465 }
466
467 func (s *TestSuite) TestLoadImageKeepReadError(c *C) {
468         // (4) Collection doesn't contain image
469         docker := NewTestDockerClient(0)
470         cr := NewContainerRunner(&ArvTestClient{}, KeepReadErrorTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
471         cr.Container.ContainerImage = hwPDH
472
473         err := cr.LoadImage()
474         c.Check(err, NotNil)
475 }
476
477 type ClosableBuffer struct {
478         bytes.Buffer
479 }
480
481 func (*ClosableBuffer) Close() error {
482         return nil
483 }
484
485 type TestLogs struct {
486         Stdout ClosableBuffer
487         Stderr ClosableBuffer
488 }
489
490 func (tl *TestLogs) NewTestLoggingWriter(logstr string) io.WriteCloser {
491         if logstr == "stdout" {
492                 return &tl.Stdout
493         }
494         if logstr == "stderr" {
495                 return &tl.Stderr
496         }
497         return nil
498 }
499
500 func dockerLog(fd byte, msg string) []byte {
501         by := []byte(msg)
502         header := make([]byte, 8+len(by))
503         header[0] = fd
504         header[7] = byte(len(by))
505         copy(header[8:], by)
506         return header
507 }
508
509 func (s *TestSuite) TestRunContainer(c *C) {
510         docker := NewTestDockerClient(0)
511         docker.fn = func(t *TestDockerClient) {
512                 t.logWriter.Write(dockerLog(1, "Hello world\n"))
513                 t.logWriter.Close()
514         }
515         cr := NewContainerRunner(&ArvTestClient{}, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
516
517         var logs TestLogs
518         cr.NewLogWriter = logs.NewTestLoggingWriter
519         cr.Container.ContainerImage = hwPDH
520         cr.Container.Command = []string{"./hw"}
521         err := cr.LoadImage()
522         c.Check(err, IsNil)
523
524         err = cr.CreateContainer()
525         c.Check(err, IsNil)
526
527         err = cr.StartContainer()
528         c.Check(err, IsNil)
529
530         err = cr.WaitFinish()
531         c.Check(err, IsNil)
532
533         c.Check(strings.HasSuffix(logs.Stdout.String(), "Hello world\n"), Equals, true)
534         c.Check(logs.Stderr.String(), Equals, "")
535 }
536
537 func (s *TestSuite) TestCommitLogs(c *C) {
538         api := &ArvTestClient{}
539         kc := &KeepTestClient{}
540         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
541         cr.CrunchLog.Timestamper = (&TestTimestamper{}).Timestamp
542
543         cr.CrunchLog.Print("Hello world!")
544         cr.CrunchLog.Print("Goodbye")
545         cr.finalState = "Complete"
546
547         err := cr.CommitLogs()
548         c.Check(err, IsNil)
549
550         c.Check(api.Calls, Equals, 2)
551         c.Check(api.Content[1]["ensure_unique_name"], Equals, true)
552         c.Check(api.Content[1]["collection"].(arvadosclient.Dict)["name"], Equals, "logs for zzzzz-zzzzz-zzzzzzzzzzzzzzz")
553         c.Check(api.Content[1]["collection"].(arvadosclient.Dict)["manifest_text"], Equals, ". 744b2e4553123b02fa7b452ec5c18993+123 0:123:crunch-run.txt\n")
554         c.Check(*cr.LogsPDH, Equals, "63da7bdacf08c40f604daad80c261e9a+60")
555 }
556
557 func (s *TestSuite) TestUpdateContainerRunning(c *C) {
558         api := &ArvTestClient{}
559         kc := &KeepTestClient{}
560         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
561
562         err := cr.UpdateContainerRunning()
563         c.Check(err, IsNil)
564
565         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["state"], Equals, "Running")
566 }
567
568 func (s *TestSuite) TestUpdateContainerComplete(c *C) {
569         api := &ArvTestClient{}
570         kc := &KeepTestClient{}
571         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
572
573         cr.LogsPDH = new(string)
574         *cr.LogsPDH = "d3a229d2fe3690c2c3e75a71a153c6a3+60"
575
576         cr.ExitCode = new(int)
577         *cr.ExitCode = 42
578         cr.finalState = "Complete"
579
580         err := cr.UpdateContainerFinal()
581         c.Check(err, IsNil)
582
583         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["log"], Equals, *cr.LogsPDH)
584         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["exit_code"], Equals, *cr.ExitCode)
585         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["state"], Equals, "Complete")
586 }
587
588 func (s *TestSuite) TestUpdateContainerCancelled(c *C) {
589         api := &ArvTestClient{}
590         kc := &KeepTestClient{}
591         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
592         cr.cCancelled = true
593         cr.finalState = "Cancelled"
594
595         err := cr.UpdateContainerFinal()
596         c.Check(err, IsNil)
597
598         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["log"], IsNil)
599         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["exit_code"], IsNil)
600         c.Check(api.Content[0]["container"].(arvadosclient.Dict)["state"], Equals, "Cancelled")
601 }
602
603 // Used by the TestFullRun*() test below to DRY up boilerplate setup to do full
604 // dress rehearsal of the Run() function, starting from a JSON container record.
605 func FullRunHelper(c *C, record string, extraMounts []string, exitCode int, fn func(t *TestDockerClient)) (api *ArvTestClient, cr *ContainerRunner, realTemp string) {
606         rec := arvados.Container{}
607         err := json.Unmarshal([]byte(record), &rec)
608         c.Check(err, IsNil)
609
610         docker := NewTestDockerClient(exitCode)
611         docker.fn = fn
612         docker.ImageRemove(nil, hwImageId, dockertypes.ImageRemoveOptions{})
613
614         api = &ArvTestClient{Container: rec}
615         docker.api = api
616         cr = NewContainerRunner(api, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
617         cr.statInterval = 100 * time.Millisecond
618         am := &ArvMountCmdLine{}
619         cr.RunArvMount = am.ArvMountTest
620
621         realTemp, err = ioutil.TempDir("", "crunchrun_test1-")
622         c.Assert(err, IsNil)
623         defer os.RemoveAll(realTemp)
624
625         docker.realTemp = realTemp
626
627         tempcount := 0
628         cr.MkTempDir = func(_ string, prefix string) (string, error) {
629                 tempcount++
630                 d := fmt.Sprintf("%s/%s%d", realTemp, prefix, tempcount)
631                 err := os.Mkdir(d, os.ModePerm)
632                 if err != nil && strings.Contains(err.Error(), ": file exists") {
633                         // Test case must have pre-populated the tempdir
634                         err = nil
635                 }
636                 return d, err
637         }
638
639         if extraMounts != nil && len(extraMounts) > 0 {
640                 err := cr.SetupArvMountPoint("keep")
641                 c.Check(err, IsNil)
642
643                 for _, m := range extraMounts {
644                         os.MkdirAll(cr.ArvMountPoint+"/by_id/"+m, os.ModePerm)
645                 }
646         }
647
648         err = cr.Run()
649         if api.CalledWith("container.state", "Complete") != nil {
650                 c.Check(err, IsNil)
651         }
652         c.Check(api.WasSetRunning, Equals, true)
653
654         c.Check(api.Content[api.Calls-1]["container"].(arvadosclient.Dict)["log"], NotNil)
655
656         if err != nil {
657                 for k, v := range api.Logs {
658                         c.Log(k)
659                         c.Log(v.String())
660                 }
661         }
662
663         return
664 }
665
666 func (s *TestSuite) TestFullRunHello(c *C) {
667         api, _, _ := FullRunHelper(c, `{
668     "command": ["echo", "hello world"],
669     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
670     "cwd": ".",
671     "environment": {},
672     "mounts": {"/tmp": {"kind": "tmp"} },
673     "output_path": "/tmp",
674     "priority": 1,
675     "runtime_constraints": {}
676 }`, nil, 0, func(t *TestDockerClient) {
677                 t.logWriter.Write(dockerLog(1, "hello world\n"))
678                 t.logWriter.Close()
679         })
680
681         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
682         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
683         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "hello world\n"), Equals, true)
684
685 }
686
687 func (s *TestSuite) TestCrunchstat(c *C) {
688         api, _, _ := FullRunHelper(c, `{
689                 "command": ["sleep", "1"],
690                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
691                 "cwd": ".",
692                 "environment": {},
693                 "mounts": {"/tmp": {"kind": "tmp"} },
694                 "output_path": "/tmp",
695                 "priority": 1,
696                 "runtime_constraints": {}
697         }`, nil, 0, func(t *TestDockerClient) {
698                 time.Sleep(time.Second)
699                 t.logWriter.Close()
700         })
701
702         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
703         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
704
705         // We didn't actually start a container, so crunchstat didn't
706         // find accounting files and therefore didn't log any stats.
707         // It should have logged a "can't find accounting files"
708         // message after one poll interval, though, so we can confirm
709         // it's alive:
710         c.Assert(api.Logs["crunchstat"], NotNil)
711         c.Check(api.Logs["crunchstat"].String(), Matches, `(?ms).*cgroup stats files have not appeared after 100ms.*`)
712
713         // The "files never appeared" log assures us that we called
714         // (*crunchstat.Reporter)Stop(), and that we set it up with
715         // the correct container ID "abcde":
716         c.Check(api.Logs["crunchstat"].String(), Matches, `(?ms).*cgroup stats files never appeared for abcde\n`)
717 }
718
719 func (s *TestSuite) TestNodeInfoLog(c *C) {
720         api, _, _ := FullRunHelper(c, `{
721                 "command": ["sleep", "1"],
722                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
723                 "cwd": ".",
724                 "environment": {},
725                 "mounts": {"/tmp": {"kind": "tmp"} },
726                 "output_path": "/tmp",
727                 "priority": 1,
728                 "runtime_constraints": {}
729         }`, nil, 0,
730                 func(t *TestDockerClient) {
731                         time.Sleep(time.Second)
732                         t.logWriter.Close()
733                 })
734
735         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
736         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
737
738         c.Assert(api.Logs["node-info"], NotNil)
739         c.Check(api.Logs["node-info"].String(), Matches, `(?ms).*Host Information.*`)
740         c.Check(api.Logs["node-info"].String(), Matches, `(?ms).*CPU Information.*`)
741         c.Check(api.Logs["node-info"].String(), Matches, `(?ms).*Memory Information.*`)
742         c.Check(api.Logs["node-info"].String(), Matches, `(?ms).*Disk Space.*`)
743         c.Check(api.Logs["node-info"].String(), Matches, `(?ms).*Disk INodes.*`)
744 }
745
746 func (s *TestSuite) TestContainerRecordLog(c *C) {
747         api, _, _ := FullRunHelper(c, `{
748                 "command": ["sleep", "1"],
749                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
750                 "cwd": ".",
751                 "environment": {},
752                 "mounts": {"/tmp": {"kind": "tmp"} },
753                 "output_path": "/tmp",
754                 "priority": 1,
755                 "runtime_constraints": {}
756         }`, nil, 0,
757                 func(t *TestDockerClient) {
758                         time.Sleep(time.Second)
759                         t.logWriter.Close()
760                 })
761
762         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
763         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
764
765         c.Assert(api.Logs["container"], NotNil)
766         c.Check(api.Logs["container"].String(), Matches, `(?ms).*container_image.*`)
767 }
768
769 func (s *TestSuite) TestFullRunStderr(c *C) {
770         api, _, _ := FullRunHelper(c, `{
771     "command": ["/bin/sh", "-c", "echo hello ; echo world 1>&2 ; exit 1"],
772     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
773     "cwd": ".",
774     "environment": {},
775     "mounts": {"/tmp": {"kind": "tmp"} },
776     "output_path": "/tmp",
777     "priority": 1,
778     "runtime_constraints": {}
779 }`, nil, 1, func(t *TestDockerClient) {
780                 t.logWriter.Write(dockerLog(1, "hello\n"))
781                 t.logWriter.Write(dockerLog(2, "world\n"))
782                 t.logWriter.Close()
783         })
784
785         final := api.CalledWith("container.state", "Complete")
786         c.Assert(final, NotNil)
787         c.Check(final["container"].(arvadosclient.Dict)["exit_code"], Equals, 1)
788         c.Check(final["container"].(arvadosclient.Dict)["log"], NotNil)
789
790         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "hello\n"), Equals, true)
791         c.Check(strings.HasSuffix(api.Logs["stderr"].String(), "world\n"), Equals, true)
792 }
793
794 func (s *TestSuite) TestFullRunDefaultCwd(c *C) {
795         api, _, _ := FullRunHelper(c, `{
796     "command": ["pwd"],
797     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
798     "cwd": ".",
799     "environment": {},
800     "mounts": {"/tmp": {"kind": "tmp"} },
801     "output_path": "/tmp",
802     "priority": 1,
803     "runtime_constraints": {}
804 }`, nil, 0, func(t *TestDockerClient) {
805                 t.logWriter.Write(dockerLog(1, t.cwd+"\n"))
806                 t.logWriter.Close()
807         })
808
809         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
810         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
811         c.Log(api.Logs["stdout"])
812         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "/\n"), Equals, true)
813 }
814
815 func (s *TestSuite) TestFullRunSetCwd(c *C) {
816         api, _, _ := FullRunHelper(c, `{
817     "command": ["pwd"],
818     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
819     "cwd": "/bin",
820     "environment": {},
821     "mounts": {"/tmp": {"kind": "tmp"} },
822     "output_path": "/tmp",
823     "priority": 1,
824     "runtime_constraints": {}
825 }`, nil, 0, func(t *TestDockerClient) {
826                 t.logWriter.Write(dockerLog(1, t.cwd+"\n"))
827                 t.logWriter.Close()
828         })
829
830         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
831         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
832         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "/bin\n"), Equals, true)
833 }
834
835 func (s *TestSuite) TestStopOnSignal(c *C) {
836         s.testStopContainer(c, func(cr *ContainerRunner) {
837                 go func() {
838                         for !cr.cStarted {
839                                 time.Sleep(time.Millisecond)
840                         }
841                         cr.SigChan <- syscall.SIGINT
842                 }()
843         })
844 }
845
846 func (s *TestSuite) TestStopOnArvMountDeath(c *C) {
847         s.testStopContainer(c, func(cr *ContainerRunner) {
848                 cr.ArvMountExit = make(chan error)
849                 go func() {
850                         cr.ArvMountExit <- exec.Command("true").Run()
851                         close(cr.ArvMountExit)
852                 }()
853         })
854 }
855
856 func (s *TestSuite) testStopContainer(c *C, setup func(cr *ContainerRunner)) {
857         record := `{
858     "command": ["/bin/sh", "-c", "echo foo && sleep 30 && echo bar"],
859     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
860     "cwd": ".",
861     "environment": {},
862     "mounts": {"/tmp": {"kind": "tmp"} },
863     "output_path": "/tmp",
864     "priority": 1,
865     "runtime_constraints": {}
866 }`
867
868         rec := arvados.Container{}
869         err := json.Unmarshal([]byte(record), &rec)
870         c.Check(err, IsNil)
871
872         docker := NewTestDockerClient(0)
873         docker.fn = func(t *TestDockerClient) {
874                 <-t.stop
875                 t.logWriter.Write(dockerLog(1, "foo\n"))
876                 t.logWriter.Close()
877         }
878         docker.ImageRemove(nil, hwImageId, dockertypes.ImageRemoveOptions{})
879
880         api := &ArvTestClient{Container: rec}
881         cr := NewContainerRunner(api, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
882         cr.RunArvMount = func([]string, string) (*exec.Cmd, error) { return nil, nil }
883         setup(cr)
884
885         done := make(chan error)
886         go func() {
887                 done <- cr.Run()
888         }()
889         select {
890         case <-time.After(20 * time.Second):
891                 pprof.Lookup("goroutine").WriteTo(os.Stderr, 1)
892                 c.Fatal("timed out")
893         case err = <-done:
894                 c.Check(err, IsNil)
895         }
896         for k, v := range api.Logs {
897                 c.Log(k)
898                 c.Log(v.String())
899         }
900
901         c.Check(api.CalledWith("container.log", nil), NotNil)
902         c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
903         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "foo\n"), Equals, true)
904 }
905
906 func (s *TestSuite) TestFullRunSetEnv(c *C) {
907         api, _, _ := FullRunHelper(c, `{
908     "command": ["/bin/sh", "-c", "echo $FROBIZ"],
909     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
910     "cwd": "/bin",
911     "environment": {"FROBIZ": "bilbo"},
912     "mounts": {"/tmp": {"kind": "tmp"} },
913     "output_path": "/tmp",
914     "priority": 1,
915     "runtime_constraints": {}
916 }`, nil, 0, func(t *TestDockerClient) {
917                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
918                 t.logWriter.Close()
919         })
920
921         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
922         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
923         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "bilbo\n"), Equals, true)
924 }
925
926 type ArvMountCmdLine struct {
927         Cmd   []string
928         token string
929 }
930
931 func (am *ArvMountCmdLine) ArvMountTest(c []string, token string) (*exec.Cmd, error) {
932         am.Cmd = c
933         am.token = token
934         return nil, nil
935 }
936
937 func stubCert(temp string) string {
938         path := temp + "/ca-certificates.crt"
939         crt, _ := os.Create(path)
940         crt.Close()
941         arvadosclient.CertFiles = []string{path}
942         return path
943 }
944
945 func (s *TestSuite) TestSetupMounts(c *C) {
946         api := &ArvTestClient{}
947         kc := &KeepTestClient{}
948         cr := NewContainerRunner(api, kc, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
949         am := &ArvMountCmdLine{}
950         cr.RunArvMount = am.ArvMountTest
951
952         realTemp, err := ioutil.TempDir("", "crunchrun_test1-")
953         c.Assert(err, IsNil)
954         certTemp, err := ioutil.TempDir("", "crunchrun_test2-")
955         c.Assert(err, IsNil)
956         stubCertPath := stubCert(certTemp)
957
958         defer os.RemoveAll(realTemp)
959         defer os.RemoveAll(certTemp)
960
961         i := 0
962         cr.MkTempDir = func(_ string, prefix string) (string, error) {
963                 i++
964                 d := fmt.Sprintf("%s/%s%d", realTemp, prefix, i)
965                 err := os.Mkdir(d, os.ModePerm)
966                 if err != nil && strings.Contains(err.Error(), ": file exists") {
967                         // Test case must have pre-populated the tempdir
968                         err = nil
969                 }
970                 return d, err
971         }
972
973         checkEmpty := func() {
974                 filepath.Walk(realTemp, func(path string, _ os.FileInfo, err error) error {
975                         c.Check(path, Equals, realTemp)
976                         c.Check(err, IsNil)
977                         return nil
978                 })
979         }
980
981         {
982                 i = 0
983                 cr.ArvMountPoint = ""
984                 cr.Container.Mounts = make(map[string]arvados.Mount)
985                 cr.Container.Mounts["/tmp"] = arvados.Mount{Kind: "tmp"}
986                 cr.OutputPath = "/tmp"
987
988                 err := cr.SetupMounts()
989                 c.Check(err, IsNil)
990                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
991                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp"})
992                 cr.CleanupDirs()
993                 checkEmpty()
994         }
995
996         {
997                 i = 0
998                 cr.ArvMountPoint = ""
999                 cr.Container.Mounts = make(map[string]arvados.Mount)
1000                 cr.Container.Mounts["/out"] = arvados.Mount{Kind: "tmp"}
1001                 cr.Container.Mounts["/tmp"] = arvados.Mount{Kind: "tmp"}
1002                 cr.OutputPath = "/out"
1003
1004                 err := cr.SetupMounts()
1005                 c.Check(err, IsNil)
1006                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
1007                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/out", realTemp + "/3:/tmp"})
1008                 cr.CleanupDirs()
1009                 checkEmpty()
1010         }
1011
1012         {
1013                 i = 0
1014                 cr.ArvMountPoint = ""
1015                 cr.Container.Mounts = make(map[string]arvados.Mount)
1016                 cr.Container.Mounts["/tmp"] = arvados.Mount{Kind: "tmp"}
1017                 cr.OutputPath = "/tmp"
1018
1019                 apiflag := true
1020                 cr.Container.RuntimeConstraints.API = &apiflag
1021
1022                 err := cr.SetupMounts()
1023                 c.Check(err, IsNil)
1024                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
1025                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp", stubCertPath + ":/etc/arvados/ca-certificates.crt:ro"})
1026                 cr.CleanupDirs()
1027                 checkEmpty()
1028
1029                 apiflag = false
1030         }
1031
1032         {
1033                 i = 0
1034                 cr.ArvMountPoint = ""
1035                 cr.Container.Mounts = map[string]arvados.Mount{
1036                         "/keeptmp": {Kind: "collection", Writable: true},
1037                 }
1038                 cr.OutputPath = "/keeptmp"
1039
1040                 os.MkdirAll(realTemp+"/keep1/tmp0", os.ModePerm)
1041
1042                 err := cr.SetupMounts()
1043                 c.Check(err, IsNil)
1044                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
1045                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/tmp0:/keeptmp"})
1046                 cr.CleanupDirs()
1047                 checkEmpty()
1048         }
1049
1050         {
1051                 i = 0
1052                 cr.ArvMountPoint = ""
1053                 cr.Container.Mounts = map[string]arvados.Mount{
1054                         "/keepinp": {Kind: "collection", PortableDataHash: "59389a8f9ee9d399be35462a0f92541c+53"},
1055                         "/keepout": {Kind: "collection", Writable: true},
1056                 }
1057                 cr.OutputPath = "/keepout"
1058
1059                 os.MkdirAll(realTemp+"/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53", os.ModePerm)
1060                 os.MkdirAll(realTemp+"/keep1/tmp0", os.ModePerm)
1061
1062                 err := cr.SetupMounts()
1063                 c.Check(err, IsNil)
1064                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
1065                 sort.StringSlice(cr.Binds).Sort()
1066                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53:/keepinp:ro",
1067                         realTemp + "/keep1/tmp0:/keepout"})
1068                 cr.CleanupDirs()
1069                 checkEmpty()
1070         }
1071
1072         {
1073                 i = 0
1074                 cr.ArvMountPoint = ""
1075                 cr.Container.RuntimeConstraints.KeepCacheRAM = 512
1076                 cr.Container.Mounts = map[string]arvados.Mount{
1077                         "/keepinp": {Kind: "collection", PortableDataHash: "59389a8f9ee9d399be35462a0f92541c+53"},
1078                         "/keepout": {Kind: "collection", Writable: true},
1079                 }
1080                 cr.OutputPath = "/keepout"
1081
1082                 os.MkdirAll(realTemp+"/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53", os.ModePerm)
1083                 os.MkdirAll(realTemp+"/keep1/tmp0", os.ModePerm)
1084
1085                 err := cr.SetupMounts()
1086                 c.Check(err, IsNil)
1087                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--file-cache", "512", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
1088                 sort.StringSlice(cr.Binds).Sort()
1089                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53:/keepinp:ro",
1090                         realTemp + "/keep1/tmp0:/keepout"})
1091                 cr.CleanupDirs()
1092                 checkEmpty()
1093         }
1094
1095         for _, test := range []struct {
1096                 in  interface{}
1097                 out string
1098         }{
1099                 {in: "foo", out: `"foo"`},
1100                 {in: nil, out: `null`},
1101                 {in: map[string]int{"foo": 123}, out: `{"foo":123}`},
1102         } {
1103                 i = 0
1104                 cr.ArvMountPoint = ""
1105                 cr.Container.Mounts = map[string]arvados.Mount{
1106                         "/mnt/test.json": {Kind: "json", Content: test.in},
1107                 }
1108                 err := cr.SetupMounts()
1109                 c.Check(err, IsNil)
1110                 sort.StringSlice(cr.Binds).Sort()
1111                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2/mountdata.json:/mnt/test.json:ro"})
1112                 content, err := ioutil.ReadFile(realTemp + "/2/mountdata.json")
1113                 c.Check(err, IsNil)
1114                 c.Check(content, DeepEquals, []byte(test.out))
1115                 cr.CleanupDirs()
1116                 checkEmpty()
1117         }
1118
1119         // Read-only mount points are allowed underneath output_dir mount point
1120         {
1121                 i = 0
1122                 cr.ArvMountPoint = ""
1123                 cr.Container.Mounts = make(map[string]arvados.Mount)
1124                 cr.Container.Mounts = map[string]arvados.Mount{
1125                         "/tmp":     {Kind: "tmp"},
1126                         "/tmp/foo": {Kind: "collection"},
1127                 }
1128                 cr.OutputPath = "/tmp"
1129
1130                 os.MkdirAll(realTemp+"/keep1/tmp0", os.ModePerm)
1131
1132                 err := cr.SetupMounts()
1133                 c.Check(err, IsNil)
1134                 c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--file-cache", "512", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
1135                 c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp", realTemp + "/keep1/tmp0:/tmp/foo:ro"})
1136                 cr.CleanupDirs()
1137                 checkEmpty()
1138         }
1139
1140         // Writable mount points are not allowed underneath output_dir mount point
1141         {
1142                 i = 0
1143                 cr.ArvMountPoint = ""
1144                 cr.Container.Mounts = make(map[string]arvados.Mount)
1145                 cr.Container.Mounts = map[string]arvados.Mount{
1146                         "/tmp":     {Kind: "tmp"},
1147                         "/tmp/foo": {Kind: "collection", Writable: true},
1148                 }
1149                 cr.OutputPath = "/tmp"
1150
1151                 err := cr.SetupMounts()
1152                 c.Check(err, NotNil)
1153                 c.Check(err, ErrorMatches, `Writable mount points are not permitted underneath the output_path.*`)
1154                 cr.CleanupDirs()
1155                 checkEmpty()
1156         }
1157
1158         // Only mount points of kind 'collection' are allowed underneath output_dir mount point
1159         {
1160                 i = 0
1161                 cr.ArvMountPoint = ""
1162                 cr.Container.Mounts = make(map[string]arvados.Mount)
1163                 cr.Container.Mounts = map[string]arvados.Mount{
1164                         "/tmp":     {Kind: "tmp"},
1165                         "/tmp/foo": {Kind: "json"},
1166                 }
1167                 cr.OutputPath = "/tmp"
1168
1169                 err := cr.SetupMounts()
1170                 c.Check(err, NotNil)
1171                 c.Check(err, ErrorMatches, `Only mount points of kind 'collection' are supported underneath the output_path.*`)
1172                 cr.CleanupDirs()
1173                 checkEmpty()
1174         }
1175
1176         // Only mount point of kind 'collection' is allowed for stdin
1177         {
1178                 i = 0
1179                 cr.ArvMountPoint = ""
1180                 cr.Container.Mounts = make(map[string]arvados.Mount)
1181                 cr.Container.Mounts = map[string]arvados.Mount{
1182                         "stdin": {Kind: "tmp"},
1183                 }
1184
1185                 err := cr.SetupMounts()
1186                 c.Check(err, NotNil)
1187                 c.Check(err, ErrorMatches, `Unsupported mount kind 'tmp' for stdin.*`)
1188                 cr.CleanupDirs()
1189                 checkEmpty()
1190         }
1191 }
1192
1193 func (s *TestSuite) TestStdout(c *C) {
1194         helperRecord := `{
1195                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1196                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1197                 "cwd": "/bin",
1198                 "environment": {"FROBIZ": "bilbo"},
1199                 "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "file", "path": "/tmp/a/b/c.out"} },
1200                 "output_path": "/tmp",
1201                 "priority": 1,
1202                 "runtime_constraints": {}
1203         }`
1204
1205         api, _, _ := FullRunHelper(c, helperRecord, nil, 0, func(t *TestDockerClient) {
1206                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
1207                 t.logWriter.Close()
1208         })
1209
1210         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1211         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1212         c.Check(api.CalledWith("collection.manifest_text", "./a/b 307372fa8fd5c146b22ae7a45b49bc31+6 0:6:c.out\n"), NotNil)
1213 }
1214
1215 // Used by the TestStdoutWithWrongPath*()
1216 func StdoutErrorRunHelper(c *C, record string, fn func(t *TestDockerClient)) (api *ArvTestClient, cr *ContainerRunner, err error) {
1217         rec := arvados.Container{}
1218         err = json.Unmarshal([]byte(record), &rec)
1219         c.Check(err, IsNil)
1220
1221         docker := NewTestDockerClient(0)
1222         docker.fn = fn
1223         docker.ImageRemove(nil, hwImageId, dockertypes.ImageRemoveOptions{})
1224
1225         api = &ArvTestClient{Container: rec}
1226         cr = NewContainerRunner(api, &KeepTestClient{}, docker, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
1227         am := &ArvMountCmdLine{}
1228         cr.RunArvMount = am.ArvMountTest
1229
1230         err = cr.Run()
1231         return
1232 }
1233
1234 func (s *TestSuite) TestStdoutWithWrongPath(c *C) {
1235         _, _, err := StdoutErrorRunHelper(c, `{
1236     "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "file", "path":"/tmpa.out"} },
1237     "output_path": "/tmp"
1238 }`, func(t *TestDockerClient) {})
1239
1240         c.Check(err, NotNil)
1241         c.Check(strings.Contains(err.Error(), "Stdout path does not start with OutputPath"), Equals, true)
1242 }
1243
1244 func (s *TestSuite) TestStdoutWithWrongKindTmp(c *C) {
1245         _, _, err := StdoutErrorRunHelper(c, `{
1246     "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "tmp", "path":"/tmp/a.out"} },
1247     "output_path": "/tmp"
1248 }`, func(t *TestDockerClient) {})
1249
1250         c.Check(err, NotNil)
1251         c.Check(strings.Contains(err.Error(), "Unsupported mount kind 'tmp' for stdout"), Equals, true)
1252 }
1253
1254 func (s *TestSuite) TestStdoutWithWrongKindCollection(c *C) {
1255         _, _, err := StdoutErrorRunHelper(c, `{
1256     "mounts": {"/tmp": {"kind": "tmp"}, "stdout": {"kind": "collection", "path":"/tmp/a.out"} },
1257     "output_path": "/tmp"
1258 }`, func(t *TestDockerClient) {})
1259
1260         c.Check(err, NotNil)
1261         c.Check(strings.Contains(err.Error(), "Unsupported mount kind 'collection' for stdout"), Equals, true)
1262 }
1263
1264 func (s *TestSuite) TestFullRunWithAPI(c *C) {
1265         os.Setenv("ARVADOS_API_HOST", "test.arvados.org")
1266         defer os.Unsetenv("ARVADOS_API_HOST")
1267         api, _, _ := FullRunHelper(c, `{
1268     "command": ["/bin/sh", "-c", "echo $ARVADOS_API_HOST"],
1269     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1270     "cwd": "/bin",
1271     "environment": {},
1272     "mounts": {"/tmp": {"kind": "tmp"} },
1273     "output_path": "/tmp",
1274     "priority": 1,
1275     "runtime_constraints": {"API": true}
1276 }`, nil, 0, func(t *TestDockerClient) {
1277                 t.logWriter.Write(dockerLog(1, t.env[1][17:]+"\n"))
1278                 t.logWriter.Close()
1279         })
1280
1281         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1282         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1283         c.Check(strings.HasSuffix(api.Logs["stdout"].String(), "test.arvados.org\n"), Equals, true)
1284         c.Check(api.CalledWith("container.output", "d41d8cd98f00b204e9800998ecf8427e+0"), NotNil)
1285 }
1286
1287 func (s *TestSuite) TestFullRunSetOutput(c *C) {
1288         os.Setenv("ARVADOS_API_HOST", "test.arvados.org")
1289         defer os.Unsetenv("ARVADOS_API_HOST")
1290         api, _, _ := FullRunHelper(c, `{
1291     "command": ["/bin/sh", "-c", "echo $ARVADOS_API_HOST"],
1292     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1293     "cwd": "/bin",
1294     "environment": {},
1295     "mounts": {"/tmp": {"kind": "tmp"} },
1296     "output_path": "/tmp",
1297     "priority": 1,
1298     "runtime_constraints": {"API": true}
1299 }`, nil, 0, func(t *TestDockerClient) {
1300                 t.api.Container.Output = "d4ab34d3d4f8a72f5c4973051ae69fab+122"
1301                 t.logWriter.Close()
1302         })
1303
1304         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1305         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1306         c.Check(api.CalledWith("container.output", "d4ab34d3d4f8a72f5c4973051ae69fab+122"), NotNil)
1307 }
1308
1309 func (s *TestSuite) TestStdoutWithExcludeFromOutputMountPointUnderOutputDir(c *C) {
1310         helperRecord := `{
1311                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1312                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1313                 "cwd": "/bin",
1314                 "environment": {"FROBIZ": "bilbo"},
1315                 "mounts": {
1316         "/tmp": {"kind": "tmp"},
1317         "/tmp/foo": {"kind": "collection",
1318                      "portable_data_hash": "a3e8f74c6f101eae01fa08bfb4e49b3a+54",
1319                      "exclude_from_output": true
1320         },
1321         "stdout": {"kind": "file", "path": "/tmp/a/b/c.out"}
1322     },
1323                 "output_path": "/tmp",
1324                 "priority": 1,
1325                 "runtime_constraints": {}
1326         }`
1327
1328         extraMounts := []string{"a3e8f74c6f101eae01fa08bfb4e49b3a+54"}
1329
1330         api, _, _ := FullRunHelper(c, helperRecord, extraMounts, 0, func(t *TestDockerClient) {
1331                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
1332                 t.logWriter.Close()
1333         })
1334
1335         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1336         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1337         c.Check(api.CalledWith("collection.manifest_text", "./a/b 307372fa8fd5c146b22ae7a45b49bc31+6 0:6:c.out\n"), NotNil)
1338 }
1339
1340 func (s *TestSuite) TestStdoutWithMultipleMountPointsUnderOutputDir(c *C) {
1341         helperRecord := `{
1342                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1343                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1344                 "cwd": "/bin",
1345                 "environment": {"FROBIZ": "bilbo"},
1346                 "mounts": {
1347         "/tmp": {"kind": "tmp"},
1348         "/tmp/foo/bar": {"kind": "collection", "portable_data_hash": "a0def87f80dd594d4675809e83bd4f15+367", "path":"/file2_in_main.txt"},
1349         "/tmp/foo/sub1": {"kind": "collection", "portable_data_hash": "a0def87f80dd594d4675809e83bd4f15+367", "path":"/subdir1"},
1350         "/tmp/foo/sub1file2": {"kind": "collection", "portable_data_hash": "a0def87f80dd594d4675809e83bd4f15+367", "path":"/subdir1/file2_in_subdir1.txt"},
1351         "/tmp/foo/baz/sub2file2": {"kind": "collection", "portable_data_hash": "a0def87f80dd594d4675809e83bd4f15+367", "path":"/subdir1/subdir2/file2_in_subdir2.txt"},
1352         "stdout": {"kind": "file", "path": "/tmp/a/b/c.out"}
1353     },
1354                 "output_path": "/tmp",
1355                 "priority": 1,
1356                 "runtime_constraints": {}
1357         }`
1358
1359         extraMounts := []string{
1360                 "a0def87f80dd594d4675809e83bd4f15+367/file2_in_main.txt",
1361                 "a0def87f80dd594d4675809e83bd4f15+367/subdir1/file2_in_subdir1.txt",
1362                 "a0def87f80dd594d4675809e83bd4f15+367/subdir1/subdir2/file2_in_subdir2.txt",
1363         }
1364
1365         api, runner, realtemp := FullRunHelper(c, helperRecord, extraMounts, 0, func(t *TestDockerClient) {
1366                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
1367                 t.logWriter.Close()
1368         })
1369
1370         c.Check(runner.Binds, DeepEquals, []string{realtemp + "/2:/tmp",
1371                 realtemp + "/keep1/by_id/a0def87f80dd594d4675809e83bd4f15+367/file2_in_main.txt:/tmp/foo/bar:ro",
1372                 realtemp + "/keep1/by_id/a0def87f80dd594d4675809e83bd4f15+367/subdir1/subdir2/file2_in_subdir2.txt:/tmp/foo/baz/sub2file2:ro",
1373                 realtemp + "/keep1/by_id/a0def87f80dd594d4675809e83bd4f15+367/subdir1:/tmp/foo/sub1:ro",
1374                 realtemp + "/keep1/by_id/a0def87f80dd594d4675809e83bd4f15+367/subdir1/file2_in_subdir1.txt:/tmp/foo/sub1file2:ro",
1375         })
1376
1377         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1378         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1379         for _, v := range api.Content {
1380                 if v["collection"] != nil {
1381                         c.Check(v["ensure_unique_name"], Equals, true)
1382                         collection := v["collection"].(arvadosclient.Dict)
1383                         if strings.Index(collection["name"].(string), "output") == 0 {
1384                                 manifest := collection["manifest_text"].(string)
1385
1386                                 c.Check(manifest, Equals, `./a/b 307372fa8fd5c146b22ae7a45b49bc31+6 0:6:c.out
1387 ./foo 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0abcdefgh11234567890@569fa8c3 9:18:bar 9:18:sub1file2
1388 ./foo/baz 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0bcdefghijk544332211@569fa8c5 9:18:sub2file2
1389 ./foo/sub1 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396cabcdefghij6419876543234@569fa8c4 0:9:file1_in_subdir1.txt 9:18:file2_in_subdir1.txt
1390 ./foo/sub1/subdir2 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0bcdefghijk544332211@569fa8c5 0:9:file1_in_subdir2.txt 9:18:file2_in_subdir2.txt
1391 `)
1392                         }
1393                 }
1394         }
1395 }
1396
1397 func (s *TestSuite) TestStdoutWithMountPointsUnderOutputDirDenormalizedManifest(c *C) {
1398         helperRecord := `{
1399                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1400                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1401                 "cwd": "/bin",
1402                 "environment": {"FROBIZ": "bilbo"},
1403                 "mounts": {
1404         "/tmp": {"kind": "tmp"},
1405         "/tmp/foo/bar": {"kind": "collection", "portable_data_hash": "b0def87f80dd594d4675809e83bd4f15+367/subdir1/file2_in_subdir1.txt"},
1406         "stdout": {"kind": "file", "path": "/tmp/a/b/c.out"}
1407     },
1408                 "output_path": "/tmp",
1409                 "priority": 1,
1410                 "runtime_constraints": {}
1411         }`
1412
1413         extraMounts := []string{
1414                 "b0def87f80dd594d4675809e83bd4f15+367/subdir1/file2_in_subdir1.txt",
1415         }
1416
1417         api, _, _ := FullRunHelper(c, helperRecord, extraMounts, 0, func(t *TestDockerClient) {
1418                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
1419                 t.logWriter.Close()
1420         })
1421
1422         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1423         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1424         for _, v := range api.Content {
1425                 if v["collection"] != nil {
1426                         collection := v["collection"].(arvadosclient.Dict)
1427                         if strings.Index(collection["name"].(string), "output") == 0 {
1428                                 manifest := collection["manifest_text"].(string)
1429
1430                                 c.Check(manifest, Equals, `./a/b 307372fa8fd5c146b22ae7a45b49bc31+6 0:6:c.out
1431 ./foo 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0abcdefgh11234567890@569fa8c3 10:17:bar
1432 `)
1433                         }
1434                 }
1435         }
1436 }
1437
1438 func (s *TestSuite) TestOutputSymlinkToInput(c *C) {
1439         helperRecord := `{
1440                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1441                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1442                 "cwd": "/bin",
1443                 "environment": {"FROBIZ": "bilbo"},
1444                 "mounts": {
1445         "/tmp": {"kind": "tmp"},
1446         "/keep/foo/sub1file2": {"kind": "collection", "portable_data_hash": "a0def87f80dd594d4675809e83bd4f15+367", "path": "/subdir1/file2_in_subdir1.txt"},
1447         "/keep/foo2": {"kind": "collection", "portable_data_hash": "a0def87f80dd594d4675809e83bd4f15+367"}
1448     },
1449                 "output_path": "/tmp",
1450                 "priority": 1,
1451                 "runtime_constraints": {}
1452         }`
1453
1454         extraMounts := []string{
1455                 "a0def87f80dd594d4675809e83bd4f15+367/subdir1/file2_in_subdir1.txt",
1456         }
1457
1458         api, _, _ := FullRunHelper(c, helperRecord, extraMounts, 0, func(t *TestDockerClient) {
1459                 os.Symlink("/keep/foo/sub1file2", t.realTemp+"/2/baz")
1460                 os.Symlink("/keep/foo2/subdir1/file2_in_subdir1.txt", t.realTemp+"/2/baz2")
1461                 os.Symlink("/keep/foo2/subdir1", t.realTemp+"/2/baz3")
1462                 os.Mkdir(t.realTemp+"/2/baz4", 0700)
1463                 os.Symlink("/keep/foo2/subdir1/file2_in_subdir1.txt", t.realTemp+"/2/baz4/baz5")
1464                 t.logWriter.Close()
1465         })
1466
1467         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1468         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1469         for _, v := range api.Content {
1470                 if v["collection"] != nil {
1471                         collection := v["collection"].(arvadosclient.Dict)
1472                         if strings.Index(collection["name"].(string), "output") == 0 {
1473                                 manifest := collection["manifest_text"].(string)
1474                                 c.Check(manifest, Equals, `. 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396cabcdefghij6419876543234@569fa8c4 9:18:baz 9:18:baz2
1475 ./baz3 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396cabcdefghij6419876543234@569fa8c4 0:9:file1_in_subdir1.txt 9:18:file2_in_subdir1.txt
1476 ./baz3/subdir2 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396c73c0bcdefghijk544332211@569fa8c5 0:9:file1_in_subdir2.txt 9:18:file2_in_subdir2.txt
1477 ./baz4 3e426d509afffb85e06c4c96a7c15e91+27+Aa124ac75e5168396cabcdefghij6419876543234@569fa8c4 9:18:baz5
1478 `)
1479                         }
1480                 }
1481         }
1482 }
1483
1484 func (s *TestSuite) TestOutputError(c *C) {
1485         helperRecord := `{
1486                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1487                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1488                 "cwd": "/bin",
1489                 "environment": {"FROBIZ": "bilbo"},
1490                 "mounts": {
1491         "/tmp": {"kind": "tmp"}
1492     },
1493                 "output_path": "/tmp",
1494                 "priority": 1,
1495                 "runtime_constraints": {}
1496         }`
1497
1498         extraMounts := []string{}
1499
1500         api, _, _ := FullRunHelper(c, helperRecord, extraMounts, 0, func(t *TestDockerClient) {
1501                 os.Symlink("/etc/hosts", t.realTemp+"/2/baz")
1502                 t.logWriter.Close()
1503         })
1504
1505         c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
1506 }
1507
1508 func (s *TestSuite) TestStdinCollectionMountPoint(c *C) {
1509         helperRecord := `{
1510                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1511                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1512                 "cwd": "/bin",
1513                 "environment": {"FROBIZ": "bilbo"},
1514                 "mounts": {
1515         "/tmp": {"kind": "tmp"},
1516         "stdin": {"kind": "collection", "portable_data_hash": "b0def87f80dd594d4675809e83bd4f15+367", "path": "/file1_in_main.txt"},
1517         "stdout": {"kind": "file", "path": "/tmp/a/b/c.out"}
1518     },
1519                 "output_path": "/tmp",
1520                 "priority": 1,
1521                 "runtime_constraints": {}
1522         }`
1523
1524         extraMounts := []string{
1525                 "b0def87f80dd594d4675809e83bd4f15+367/file1_in_main.txt",
1526         }
1527
1528         api, _, _ := FullRunHelper(c, helperRecord, extraMounts, 0, func(t *TestDockerClient) {
1529                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
1530                 t.logWriter.Close()
1531         })
1532
1533         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1534         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1535         for _, v := range api.Content {
1536                 if v["collection"] != nil {
1537                         collection := v["collection"].(arvadosclient.Dict)
1538                         if strings.Index(collection["name"].(string), "output") == 0 {
1539                                 manifest := collection["manifest_text"].(string)
1540                                 c.Check(manifest, Equals, `./a/b 307372fa8fd5c146b22ae7a45b49bc31+6 0:6:c.out
1541 `)
1542                         }
1543                 }
1544         }
1545 }
1546
1547 func (s *TestSuite) TestStdinJsonMountPoint(c *C) {
1548         helperRecord := `{
1549                 "command": ["/bin/sh", "-c", "echo $FROBIZ"],
1550                 "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1551                 "cwd": "/bin",
1552                 "environment": {"FROBIZ": "bilbo"},
1553                 "mounts": {
1554         "/tmp": {"kind": "tmp"},
1555         "stdin": {"kind": "json", "content": "foo"},
1556         "stdout": {"kind": "file", "path": "/tmp/a/b/c.out"}
1557     },
1558                 "output_path": "/tmp",
1559                 "priority": 1,
1560                 "runtime_constraints": {}
1561         }`
1562
1563         api, _, _ := FullRunHelper(c, helperRecord, nil, 0, func(t *TestDockerClient) {
1564                 t.logWriter.Write(dockerLog(1, t.env[0][7:]+"\n"))
1565                 t.logWriter.Close()
1566         })
1567
1568         c.Check(api.CalledWith("container.exit_code", 0), NotNil)
1569         c.Check(api.CalledWith("container.state", "Complete"), NotNil)
1570         for _, v := range api.Content {
1571                 if v["collection"] != nil {
1572                         collection := v["collection"].(arvadosclient.Dict)
1573                         if strings.Index(collection["name"].(string), "output") == 0 {
1574                                 manifest := collection["manifest_text"].(string)
1575                                 c.Check(manifest, Equals, `./a/b 307372fa8fd5c146b22ae7a45b49bc31+6 0:6:c.out
1576 `)
1577                         }
1578                 }
1579         }
1580 }
1581
1582 func (s *TestSuite) TestStderrMount(c *C) {
1583         api, _, _ := FullRunHelper(c, `{
1584     "command": ["/bin/sh", "-c", "echo hello;exit 1"],
1585     "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
1586     "cwd": ".",
1587     "environment": {},
1588     "mounts": {"/tmp": {"kind": "tmp"},
1589                "stdout": {"kind": "file", "path": "/tmp/a/out.txt"},
1590                "stderr": {"kind": "file", "path": "/tmp/b/err.txt"}},
1591     "output_path": "/tmp",
1592     "priority": 1,
1593     "runtime_constraints": {}
1594 }`, nil, 1, func(t *TestDockerClient) {
1595                 t.logWriter.Write(dockerLog(1, "hello\n"))
1596                 t.logWriter.Write(dockerLog(2, "oops\n"))
1597                 t.logWriter.Close()
1598         })
1599
1600         final := api.CalledWith("container.state", "Complete")
1601         c.Assert(final, NotNil)
1602         c.Check(final["container"].(arvadosclient.Dict)["exit_code"], Equals, 1)
1603         c.Check(final["container"].(arvadosclient.Dict)["log"], NotNil)
1604
1605         c.Check(api.CalledWith("collection.manifest_text", "./a b1946ac92492d2347c6235b4d2611184+6 0:6:out.txt\n./b 38af5c54926b620264ab1501150cf189+5 0:5:err.txt\n"), NotNil)
1606 }