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