Merge branch '12614-broken-docker' refs #12614
[arvados.git] / services / crunch-run / crunchrun_test.go
index 5e77d7bd7bcd41fb19c80ede9b450a542cbe0635..e1d9fed730ea5ace0393b07e8b1fd8f1eaff65e4 100644 (file)
@@ -130,8 +130,21 @@ func (t *TestDockerClient) ContainerCreate(ctx context.Context, config *dockerco
 }
 
 func (t *TestDockerClient) ContainerStart(ctx context.Context, container string, options dockertypes.ContainerStartOptions) error {
+       if t.finish == 3 {
+               return errors.New(`Error response from daemon: oci runtime error: container_linux.go:247: starting container process caused "process_linux.go:359: container init caused \"rootfs_linux.go:54: mounting \\\"/tmp/keep453790790/by_id/99999999999999999999999999999999+99999/myGenome\\\" to rootfs \\\"/tmp/docker/overlay2/9999999999999999999999999999999999999999999999999999999999999999/merged\\\" at \\\"/tmp/docker/overlay2/9999999999999999999999999999999999999999999999999999999999999999/merged/keep/99999999999999999999999999999999+99999/myGenome\\\" caused \\\"no such file or directory\\\"\""`)
+       }
+       if t.finish == 4 {
+               return errors.New(`panic: standard_init_linux.go:175: exec user process caused "no such file or directory"`)
+       }
+       if t.finish == 5 {
+               return errors.New(`Error response from daemon: Cannot start container 41f26cbc43bcc1280f4323efb1830a394ba8660c9d1c2b564ba42bf7f7694845: [8] System error: no such file or directory`)
+       }
+       if t.finish == 6 {
+               return errors.New(`Error response from daemon: Cannot start container 58099cd76c834f3dc2a4fb76c8028f049ae6d4fdf0ec373e1f2cfea030670c2d: [8] System error: exec: "foobar": executable file not found in $PATH`)
+       }
+
        if container == "abcde" {
-               go t.fn(t)
+               // t.fn gets executed in ContainerWait
                return nil
        } else {
                return errors.New("Invalid container id")
@@ -147,6 +160,7 @@ func (t *TestDockerClient) ContainerWait(ctx context.Context, container string,
        body := make(chan dockercontainer.ContainerWaitOKBody)
        err := make(chan error)
        go func() {
+               t.fn(t)
                body <- dockercontainer.ContainerWaitOKBody{StatusCode: int64(t.finish)}
                close(body)
                close(err)
@@ -155,6 +169,10 @@ func (t *TestDockerClient) ContainerWait(ctx context.Context, container string,
 }
 
 func (t *TestDockerClient) ImageInspectWithRaw(ctx context.Context, image string) (dockertypes.ImageInspect, []byte, error) {
+       if t.finish == 2 {
+               return dockertypes.ImageInspect{}, nil, fmt.Errorf("Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?")
+       }
+
        if t.imageLoaded == image {
                return dockertypes.ImageInspect{}, nil, nil
        } else {
@@ -163,6 +181,9 @@ func (t *TestDockerClient) ImageInspectWithRaw(ctx context.Context, image string
 }
 
 func (t *TestDockerClient) ImageLoad(ctx context.Context, input io.Reader, quiet bool) (dockertypes.ImageLoadResponse, error) {
+       if t.finish == 2 {
+               return dockertypes.ImageLoadResponse{}, fmt.Errorf("Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?")
+       }
        _, err := io.Copy(ioutil.Discard, input)
        if err != nil {
                return dockertypes.ImageLoadResponse{}, err
@@ -320,11 +341,27 @@ type FileWrapper struct {
        len int64
 }
 
+func (fw FileWrapper) Readdir(n int) ([]os.FileInfo, error) {
+       return nil, errors.New("not implemented")
+}
+
+func (fw FileWrapper) Seek(int64, int) (int64, error) {
+       return 0, errors.New("not implemented")
+}
+
 func (fw FileWrapper) Size() int64 {
        return fw.len
 }
 
-func (fw FileWrapper) Seek(int64, int) (int64, error) {
+func (fw FileWrapper) Stat() (os.FileInfo, error) {
+       return nil, errors.New("not implemented")
+}
+
+func (fw FileWrapper) Truncate(int64) error {
+       return errors.New("not implemented")
+}
+
+func (fw FileWrapper) Write([]byte) (int, error) {
        return 0, errors.New("not implemented")
 }
 
@@ -432,20 +469,14 @@ func (KeepReadErrorTestClient) PutHB(hash string, buf []byte) (string, int, erro
 func (KeepReadErrorTestClient) ClearBlockCache() {
 }
 
-type ErrorReader struct{}
+type ErrorReader struct {
+       FileWrapper
+}
 
 func (ErrorReader) Read(p []byte) (n int, err error) {
        return 0, errors.New("ErrorReader")
 }
 
-func (ErrorReader) Close() error {
-       return nil
-}
-
-func (ErrorReader) Size() int64 {
-       return 0
-}
-
 func (ErrorReader) Seek(int64, int) (int64, error) {
        return 0, errors.New("ErrorReader")
 }
@@ -667,9 +698,10 @@ func FullRunHelper(c *C, record string, extraMounts []string, exitCode int, fn f
        if api.CalledWith("container.state", "Complete") != nil {
                c.Check(err, IsNil)
        }
-       c.Check(api.WasSetRunning, Equals, true)
-
-       c.Check(api.Content[api.Calls-1]["container"].(arvadosclient.Dict)["log"], NotNil)
+       if exitCode != 2 {
+               c.Check(api.WasSetRunning, Equals, true)
+               c.Check(api.Content[api.Calls-2]["container"].(arvadosclient.Dict)["log"], NotNil)
+       }
 
        if err != nil {
                for k, v := range api.Logs {
@@ -1002,11 +1034,14 @@ func (s *TestSuite) TestSetupMounts(c *C) {
                cr.Container.Mounts = make(map[string]arvados.Mount)
                cr.Container.Mounts["/tmp"] = arvados.Mount{Kind: "tmp"}
                cr.OutputPath = "/tmp"
-
+               cr.statInterval = 5 * time.Second
                err := cr.SetupMounts()
                c.Check(err, IsNil)
-               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
+               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other",
+                       "--read-write", "--crunchstat-interval=5",
+                       "--mount-by-pdh", "by_id", realTemp + "/keep1"})
                c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp"})
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1021,8 +1056,11 @@ func (s *TestSuite) TestSetupMounts(c *C) {
 
                err := cr.SetupMounts()
                c.Check(err, IsNil)
-               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
+               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other",
+                       "--read-write", "--crunchstat-interval=5",
+                       "--mount-by-pdh", "by_id", realTemp + "/keep1"})
                c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/out", realTemp + "/3:/tmp"})
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1039,8 +1077,11 @@ func (s *TestSuite) TestSetupMounts(c *C) {
 
                err := cr.SetupMounts()
                c.Check(err, IsNil)
-               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
+               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other",
+                       "--read-write", "--crunchstat-interval=5",
+                       "--mount-by-pdh", "by_id", realTemp + "/keep1"})
                c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp", stubCertPath + ":/etc/arvados/ca-certificates.crt:ro"})
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
 
@@ -1059,8 +1100,11 @@ func (s *TestSuite) TestSetupMounts(c *C) {
 
                err := cr.SetupMounts()
                c.Check(err, IsNil)
-               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
+               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other",
+                       "--read-write", "--crunchstat-interval=5",
+                       "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
                c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/tmp0:/keeptmp"})
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1079,10 +1123,13 @@ func (s *TestSuite) TestSetupMounts(c *C) {
 
                err := cr.SetupMounts()
                c.Check(err, IsNil)
-               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
+               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other",
+                       "--read-write", "--crunchstat-interval=5",
+                       "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
                sort.StringSlice(cr.Binds).Sort()
                c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53:/keepinp:ro",
                        realTemp + "/keep1/tmp0:/keepout"})
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1102,10 +1149,13 @@ func (s *TestSuite) TestSetupMounts(c *C) {
 
                err := cr.SetupMounts()
                c.Check(err, IsNil)
-               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--file-cache", "512", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
+               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other",
+                       "--read-write", "--crunchstat-interval=5",
+                       "--file-cache", "512", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
                sort.StringSlice(cr.Binds).Sort()
                c.Check(cr.Binds, DeepEquals, []string{realTemp + "/keep1/by_id/59389a8f9ee9d399be35462a0f92541c+53:/keepinp:ro",
                        realTemp + "/keep1/tmp0:/keepout"})
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1130,6 +1180,7 @@ func (s *TestSuite) TestSetupMounts(c *C) {
                content, err := ioutil.ReadFile(realTemp + "/2/mountdata.json")
                c.Check(err, IsNil)
                c.Check(content, DeepEquals, []byte(test.out))
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1149,8 +1200,11 @@ func (s *TestSuite) TestSetupMounts(c *C) {
 
                err := cr.SetupMounts()
                c.Check(err, IsNil)
-               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other", "--read-write", "--file-cache", "512", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
+               c.Check(am.Cmd, DeepEquals, []string{"--foreground", "--allow-other",
+                       "--read-write", "--crunchstat-interval=5",
+                       "--file-cache", "512", "--mount-tmp", "tmp0", "--mount-by-pdh", "by_id", realTemp + "/keep1"})
                c.Check(cr.Binds, DeepEquals, []string{realTemp + "/2:/tmp", realTemp + "/keep1/tmp0:/tmp/foo:ro"})
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1169,6 +1223,7 @@ func (s *TestSuite) TestSetupMounts(c *C) {
                err := cr.SetupMounts()
                c.Check(err, NotNil)
                c.Check(err, ErrorMatches, `Writable mount points are not permitted underneath the output_path.*`)
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1187,6 +1242,7 @@ func (s *TestSuite) TestSetupMounts(c *C) {
                err := cr.SetupMounts()
                c.Check(err, NotNil)
                c.Check(err, ErrorMatches, `Only mount points of kind 'collection' are supported underneath the output_path.*`)
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1203,6 +1259,7 @@ func (s *TestSuite) TestSetupMounts(c *C) {
                err := cr.SetupMounts()
                c.Check(err, NotNil)
                c.Check(err, ErrorMatches, `Unsupported mount kind 'tmp' for stdin.*`)
+               os.RemoveAll(cr.ArvMountPoint)
                cr.CleanupDirs()
                checkEmpty()
        }
@@ -1523,6 +1580,59 @@ func (s *TestSuite) TestOutputError(c *C) {
        c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
 }
 
+func (s *TestSuite) TestOutputSymlinkToOutput(c *C) {
+       helperRecord := `{
+               "command": ["/bin/sh", "-c", "echo $FROBIZ"],
+               "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
+               "cwd": "/bin",
+               "environment": {"FROBIZ": "bilbo"},
+               "mounts": {
+        "/tmp": {"kind": "tmp"}
+    },
+               "output_path": "/tmp",
+               "priority": 1,
+               "runtime_constraints": {}
+       }`
+
+       extraMounts := []string{}
+
+       api, _, _ := FullRunHelper(c, helperRecord, extraMounts, 0, func(t *TestDockerClient) {
+               rf, _ := os.Create(t.realTemp + "/2/realfile")
+               rf.Write([]byte("foo"))
+               rf.Close()
+
+               os.Mkdir(t.realTemp+"/2/realdir", 0700)
+               rf, _ = os.Create(t.realTemp + "/2/realdir/subfile")
+               rf.Write([]byte("bar"))
+               rf.Close()
+
+               os.Symlink("/tmp/realfile", t.realTemp+"/2/file1")
+               os.Symlink("realfile", t.realTemp+"/2/file2")
+               os.Symlink("/tmp/file1", t.realTemp+"/2/file3")
+               os.Symlink("file2", t.realTemp+"/2/file4")
+               os.Symlink("realdir", t.realTemp+"/2/dir1")
+               os.Symlink("/tmp/realdir", t.realTemp+"/2/dir2")
+               t.logWriter.Close()
+       })
+
+       c.Check(api.CalledWith("container.exit_code", 0), NotNil)
+       c.Check(api.CalledWith("container.state", "Complete"), NotNil)
+       for _, v := range api.Content {
+               if v["collection"] != nil {
+                       collection := v["collection"].(arvadosclient.Dict)
+                       if strings.Index(collection["name"].(string), "output") == 0 {
+                               manifest := collection["manifest_text"].(string)
+                               c.Check(manifest, Equals,
+                                       `. 7a2c86e102dcc231bd232aad99686dfa+15 0:3:file1 3:3:file2 6:3:file3 9:3:file4 12:3:realfile
+./dir1 37b51d194a7513e45b56f6524f2d51f2+3 0:3:subfile
+./dir2 37b51d194a7513e45b56f6524f2d51f2+3 0:3:subfile
+./realdir 37b51d194a7513e45b56f6524f2d51f2+3 0:3:subfile
+`)
+                       }
+               }
+       }
+}
+
 func (s *TestSuite) TestStdinCollectionMountPoint(c *C) {
        helperRecord := `{
                "command": ["/bin/sh", "-c", "echo $FROBIZ"],
@@ -1632,3 +1742,197 @@ func (s *TestSuite) TestNumberRoundTrip(c *C) {
        c.Check(err, IsNil)
        c.Check(string(jsondata), Equals, `{"number":123456789123456789}`)
 }
+
+func (s *TestSuite) TestEvalSymlinks(c *C) {
+       cr := NewContainerRunner(&ArvTestClient{callraw: true}, &KeepTestClient{}, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
+
+       realTemp, err := ioutil.TempDir("", "crunchrun_test-")
+       c.Assert(err, IsNil)
+       defer os.RemoveAll(realTemp)
+
+       cr.HostOutputDir = realTemp
+
+       // Absolute path outside output dir
+       os.Symlink("/etc/passwd", realTemp+"/p1")
+
+       // Relative outside output dir
+       os.Symlink("../zip", realTemp+"/p2")
+
+       // Circular references
+       os.Symlink("p4", realTemp+"/p3")
+       os.Symlink("p5", realTemp+"/p4")
+       os.Symlink("p3", realTemp+"/p5")
+
+       // Target doesn't exist
+       os.Symlink("p99", realTemp+"/p6")
+
+       for _, v := range []string{"p1", "p2", "p3", "p4", "p5"} {
+               info, err := os.Lstat(realTemp + "/" + v)
+               _, _, _, err = cr.derefOutputSymlink(realTemp+"/"+v, info)
+               c.Assert(err, NotNil)
+       }
+}
+
+func (s *TestSuite) TestEvalSymlinkDir(c *C) {
+       cr := NewContainerRunner(&ArvTestClient{callraw: true}, &KeepTestClient{}, nil, "zzzzz-zzzzz-zzzzzzzzzzzzzzz")
+
+       realTemp, err := ioutil.TempDir("", "crunchrun_test-")
+       c.Assert(err, IsNil)
+       defer os.RemoveAll(realTemp)
+
+       cr.HostOutputDir = realTemp
+
+       // Absolute path outside output dir
+       os.Symlink(".", realTemp+"/loop")
+
+       v := "loop"
+       info, err := os.Lstat(realTemp + "/" + v)
+       _, err = cr.UploadOutputFile(realTemp+"/"+v, info, err, []string{}, nil, "", "", 0)
+       c.Assert(err, NotNil)
+}
+
+func (s *TestSuite) TestFullBrokenDocker1(c *C) {
+       tf, err := ioutil.TempFile("", "brokenNodeHook-")
+       c.Assert(err, IsNil)
+       defer os.Remove(tf.Name())
+
+       tf.Write([]byte(`#!/bin/sh
+exec echo killme
+`))
+       tf.Close()
+       os.Chmod(tf.Name(), 0700)
+
+       ech := tf.Name()
+       brokenNodeHook = &ech
+
+       api, _, _ := FullRunHelper(c, `{
+    "command": ["echo", "hello world"],
+    "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
+    "cwd": ".",
+    "environment": {},
+    "mounts": {"/tmp": {"kind": "tmp"} },
+    "output_path": "/tmp",
+    "priority": 1,
+    "runtime_constraints": {}
+}`, nil, 2, func(t *TestDockerClient) {
+               t.logWriter.Write(dockerLog(1, "hello world\n"))
+               t.logWriter.Close()
+       })
+
+       c.Check(api.CalledWith("container.state", "Queued"), NotNil)
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*unable to run containers.*")
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*Running broken node hook.*")
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*killme.*")
+
+}
+
+func (s *TestSuite) TestFullBrokenDocker2(c *C) {
+       ech := ""
+       brokenNodeHook = &ech
+
+       api, _, _ := FullRunHelper(c, `{
+    "command": ["echo", "hello world"],
+    "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
+    "cwd": ".",
+    "environment": {},
+    "mounts": {"/tmp": {"kind": "tmp"} },
+    "output_path": "/tmp",
+    "priority": 1,
+    "runtime_constraints": {}
+}`, nil, 2, func(t *TestDockerClient) {
+               t.logWriter.Write(dockerLog(1, "hello world\n"))
+               t.logWriter.Close()
+       })
+
+       c.Check(api.CalledWith("container.state", "Queued"), NotNil)
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*unable to run containers.*")
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*No broken node hook.*")
+}
+
+func (s *TestSuite) TestFullBrokenDocker3(c *C) {
+       ech := ""
+       brokenNodeHook = &ech
+
+       api, _, _ := FullRunHelper(c, `{
+    "command": ["echo", "hello world"],
+    "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
+    "cwd": ".",
+    "environment": {},
+    "mounts": {"/tmp": {"kind": "tmp"} },
+    "output_path": "/tmp",
+    "priority": 1,
+    "runtime_constraints": {}
+}`, nil, 3, func(t *TestDockerClient) {
+               t.logWriter.Write(dockerLog(1, "hello world\n"))
+               t.logWriter.Close()
+       })
+
+       c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*unable to run containers.*")
+}
+
+func (s *TestSuite) TestBadCommand1(c *C) {
+       ech := ""
+       brokenNodeHook = &ech
+
+       api, _, _ := FullRunHelper(c, `{
+    "command": ["echo", "hello world"],
+    "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
+    "cwd": ".",
+    "environment": {},
+    "mounts": {"/tmp": {"kind": "tmp"} },
+    "output_path": "/tmp",
+    "priority": 1,
+    "runtime_constraints": {}
+}`, nil, 4, func(t *TestDockerClient) {
+               t.logWriter.Write(dockerLog(1, "hello world\n"))
+               t.logWriter.Close()
+       })
+
+       c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*Possible causes:.*is missing.*")
+}
+
+func (s *TestSuite) TestBadCommand2(c *C) {
+       ech := ""
+       brokenNodeHook = &ech
+
+       api, _, _ := FullRunHelper(c, `{
+    "command": ["echo", "hello world"],
+    "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
+    "cwd": ".",
+    "environment": {},
+    "mounts": {"/tmp": {"kind": "tmp"} },
+    "output_path": "/tmp",
+    "priority": 1,
+    "runtime_constraints": {}
+}`, nil, 5, func(t *TestDockerClient) {
+               t.logWriter.Write(dockerLog(1, "hello world\n"))
+               t.logWriter.Close()
+       })
+
+       c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*Possible causes:.*is missing.*")
+}
+
+func (s *TestSuite) TestBadCommand3(c *C) {
+       ech := ""
+       brokenNodeHook = &ech
+
+       api, _, _ := FullRunHelper(c, `{
+    "command": ["echo", "hello world"],
+    "container_image": "d4ab34d3d4f8a72f5c4973051ae69fab+122",
+    "cwd": ".",
+    "environment": {},
+    "mounts": {"/tmp": {"kind": "tmp"} },
+    "output_path": "/tmp",
+    "priority": 1,
+    "runtime_constraints": {}
+}`, nil, 6, func(t *TestDockerClient) {
+               t.logWriter.Write(dockerLog(1, "hello world\n"))
+               t.logWriter.Close()
+       })
+
+       c.Check(api.CalledWith("container.state", "Cancelled"), NotNil)
+       c.Check(api.Logs["crunch-run"].String(), Matches, "(?ms).*Possible causes:.*is missing.*")
+}