mitchellh / panicwrap

panicwrap is a Go library for catching and handling panics in Go applications.
https://gist.github.com/mitchellh/90029601268e59a29e64e55bab1c5bdc
MIT License
443 stars 69 forks source link

Child process exits with exitcode -1 on OSX, causes double-run #18

Open Groxx opened 7 years ago

Groxx commented 7 years ago

Maybe I'm misusing it? My code looks like this:

func main() {
    wrap := flag.Bool("panicwrap", true, "if true (the default), launch with panicwrap.  When debugging, you probably want to pass 'false'.")
    flag.Parse()
    if *wrap {
        exitStatus, err := panicwrap.BasicWrap(panicHandler)
        if err != nil {
            panic(err)
        }

        // If exitStatus >= 0, then we're the parent process and the panicwrap
        // re-executed ourselves and completed. Just exit with the proper status.
        if exitStatus >= 0 {
            os.Exit(exitStatus)
        }
        log.Info("exitStatus: ", exitStatus)
        log.Info("wrapped? ", panicwrap.Wrapped(nil))
    }

        log.Info("running app")
        // ...
        select {}
}

When I run this, I get logs like:

{"level":"info","msg":"main.go:33 exitStatus: -1","time":"2017-05-17T18:48:57-07:00"}
{"level":"info","msg":"main.go:34 wrapped? true","time":"2017-05-17T18:48:57-07:00"}
{"level":"info","msg":"main.go:47 running app","time":"2017-05-17T18:48:57-07:00"}
... then I hit Ctrl-C
{"level":"info","msg":"main.go:33 exitStatus: -1","time":"2017-05-17T18:49:03-07:00"}
{"level":"info","msg":"main.go:34 wrapped? false","time":"2017-05-17T18:49:03-07:00"}
{"level":"info","msg":"main.go:47 running app","time":"2017-05-17T18:49:03-07:00"}
... have to hit Ctrl-C again to kill the process

This happens both when Ctrl-C-ing, and when I kill [pid] on the child process. If I intentionally divide by zero though, it's caught and stops correctly, so that's great so far!

I added some logs around:

func Wrap(c *WrapConfig) (int, error) {
        // ...
    if err := cmd.Wait(); err != nil {
        exitErr, ok := err.(*exec.ExitError)
        if !ok {
            // This is some other kind of subprocessing error.
            return 1, err
        }

        exitStatus := 1
        if status, ok := exitErr.Sys().(syscall.WaitStatus); ok {
            exitStatus = status.ExitStatus()
            log.Infof("Status verbose: %#v", status)
            log.Info("status: ", status)
            log.Info("exit: ", status.ExitStatus())
        }

Which gives me logs like:

... Ctrl-C
{"level":"info","msg":"panicwrap.go:213 Status verbose: 0x2","time":"2017-05-17T18:48:51-07:00"}
{"level":"info","msg":"panicwrap.go:214 status: 2","time":"2017-05-17T18:48:51-07:00"}
{"level":"info","msg":"panicwrap.go:215 exit: -1","time":"2017-05-17T18:48:51-07:00"}
... or if I kill [pid]
{"level":"info","msg":"panicwrap.go:213 Status verbose: 0xf","time":"2017-05-17T18:49:03-07:00"}
{"level":"info","msg":"panicwrap.go:214 status: 15","time":"2017-05-17T18:49:03-07:00"}
{"level":"info","msg":"panicwrap.go:215 exit: -1","time":"2017-05-17T18:49:03-07:00"}

I can work around this by checking if *flag && !wrapped { return }, but it seems like the cmd.Wait() response isn't what this project expects - -1 is returned if the status isn't exited:

// go 1.8 syscall_bsd.go
func (w WaitStatus) ExitStatus() int {
    if w&mask != exited {
        return -1
    }
    return int(w >> shift)
}

Since -1 is also a "you're the child process" value, the example code in the readme leads to incorrect behavior.

I don't know what a fix would be, but I'm happy to help debug!

ddatsh commented 7 years ago

+1 go 1.9 os: win10,centos