panicwrap icon indicating copy to clipboard operation
panicwrap copied to clipboard

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

Open Groxx opened this issue 7 years ago • 1 comments

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!

Groxx avatar May 18 '17 02:05 Groxx

+1 go 1.9 os: win10,centos

ddatsh avatar Aug 31 '17 16:08 ddatsh