18513: Decipher status code in crunch-run.txt log.
authorTom Clegg <tom@curii.com>
Tue, 18 Jan 2022 15:13:50 +0000 (10:13 -0500)
committerTom Clegg <tom@curii.com>
Tue, 18 Jan 2022 15:13:50 +0000 (10:13 -0500)
Container exited with status code 137 (signal 9, SIGKILL)

Previously, docker mode just said "exited with code: 137" and
singularity mode didn't mention it at all.

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tom@curii.com>

lib/crunchrun/crunchrun.go
lib/crunchrun/crunchrun_test.go
lib/crunchrun/docker.go
lib/crunchrun/executor_test.go

index fb2200a56b8760e5e2e655ce82aacb8fc2d56815..af0d49c80e61e65a1120d6aa07ecd1601a064534 100644 (file)
@@ -36,6 +36,7 @@ import (
        "git.arvados.org/arvados.git/sdk/go/arvadosclient"
        "git.arvados.org/arvados.git/sdk/go/keepclient"
        "git.arvados.org/arvados.git/sdk/go/manifest"
+       "golang.org/x/sys/unix"
 )
 
 type command struct{}
@@ -1056,6 +1057,20 @@ func (runner *ContainerRunner) WaitFinish() error {
        }
        runner.ExitCode = &exitcode
 
+       extra := ""
+       if exitcode&0x80 != 0 {
+               // Convert raw exit status (0x80 + signal number) to a
+               // string to log after the code, like " (signal 101)"
+               // or " (signal 9, killed)"
+               sig := syscall.WaitStatus(exitcode).Signal()
+               if name := unix.SignalName(sig); name != "" {
+                       extra = fmt.Sprintf(" (signal %d, %s)", sig, name)
+               } else {
+                       extra = fmt.Sprintf(" (signal %d)", sig)
+               }
+       }
+       runner.CrunchLog.Printf("Container exited with status code %d%s", exitcode, extra)
+
        var returnErr error
        if err = runner.executorStdin.Close(); err != nil {
                err = fmt.Errorf("error closing container stdin: %s", err)
index 97f91103a072ff124651ffe475da1e1b2da71c95..2ec35f0559c0828077d4adbe30b1d96dbe3c0976 100644 (file)
@@ -1567,6 +1567,7 @@ func (s *TestSuite) TestFullRunWithAPI(c *C) {
        })
        c.Check(s.api.CalledWith("container.exit_code", 3), NotNil)
        c.Check(s.api.CalledWith("container.state", "Complete"), NotNil)
+       c.Check(s.api.Logs["crunch-run"].String(), Matches, `(?ms).*status code 3\n.*`)
 }
 
 func (s *TestSuite) TestFullRunSetOutput(c *C) {
@@ -1599,7 +1600,7 @@ func (s *TestSuite) TestArvMountRuntimeStatusWarning(c *C) {
        }
        s.executor.runFunc = func() {
                time.Sleep(time.Second)
-               s.executor.exit <- 0
+               s.executor.exit <- 137
        }
        record := `{
     "command": ["sleep", "1"],
@@ -1616,10 +1617,11 @@ func (s *TestSuite) TestArvMountRuntimeStatusWarning(c *C) {
        c.Assert(err, IsNil)
        err = s.runner.Run()
        c.Assert(err, IsNil)
-       c.Check(s.api.CalledWith("container.exit_code", 0), NotNil)
+       c.Check(s.api.CalledWith("container.exit_code", 137), NotNil)
        c.Check(s.api.CalledWith("container.runtime_status.warning", "arv-mount: Keep write error"), NotNil)
        c.Check(s.api.CalledWith("container.runtime_status.warningDetail", "Test: Keep write error: I am a teapot"), NotNil)
        c.Check(s.api.CalledWith("container.state", "Complete"), NotNil)
+       c.Check(s.api.Logs["crunch-run"].String(), Matches, `(?ms).*Container exited with status code 137 \(signal 9, SIGKILL\).*`)
 }
 
 func (s *TestSuite) TestStdoutWithExcludeFromOutputMountPointUnderOutputDir(c *C) {
index 06e5b5b1ece5794881e8a5cc04c05059563e358d..e62f2a39ba36e0b23d149d50f5062344a1f0aff1 100644 (file)
@@ -215,7 +215,6 @@ func (e *dockerExecutor) Wait(ctx context.Context) (int, error) {
        for {
                select {
                case waitBody := <-waitOk:
-                       e.logf("Container exited with code: %v", waitBody.StatusCode)
                        // wait for stdout/stderr to complete
                        <-e.doneIO
                        return int(waitBody.StatusCode), nil
index 08c7140add8245a39f029328d43ad1ff64114155..99af0530ff35dd55e2163c8726e09699b06d5852 100644 (file)
@@ -86,6 +86,22 @@ func (s *executorSuite) TestExecTrivialContainer(c *C) {
        c.Check(s.stderr.String(), Equals, "")
 }
 
+func (s *executorSuite) TestExitStatus(c *C) {
+       s.spec.Command = []string{"false"}
+       s.checkRun(c, 1)
+}
+
+func (s *executorSuite) TestSignalExitStatus(c *C) {
+       if _, isdocker := s.executor.(*dockerExecutor); isdocker {
+               // It's not quite this easy to make busybox kill
+               // itself in docker where it's pid 1.
+               c.Skip("kill -9 $$ doesn't work on busybox with pid=1 in docker")
+               return
+       }
+       s.spec.Command = []string{"sh", "-c", "kill -9 $$"}
+       s.checkRun(c, 0x80+9)
+}
+
 func (s *executorSuite) TestExecStop(c *C) {
        s.spec.Command = []string{"sh", "-c", "sleep 10; echo ok"}
        err := s.executor.Create(s.spec)