New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

syscall: ForkExec with Ptrace flag causes runtime to be traced #21428

Closed
bjames2011 opened this Issue Aug 13, 2017 · 17 comments

Comments

Projects
None yet
6 participants
@bjames2011

bjames2011 commented Aug 13, 2017

Environment

> go version
go version go1.6.2 linux/amd64

> uname -a
Linux yoga 4.4.0-83-generic #106-Ubuntu SMP Mon Jun 26 17:54:43 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

> go env
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/bjames/Dropbox/go"
GORACE=""
GOROOT="/usr/lib/go-1.6"
GOTOOLDIR="/usr/lib/go-1.6/pkg/tool/linux_amd64"
GO15VENDOREXPERIMENT="1"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0"
CXX="g++"
CGO_ENABLED="1"

Issue

This is somewhat of a philosophical question about the design decisions made in the Go runtime, rather than a bug, per-se.

I've been trying to implement a simple strace-like program in Golang, using syscall.ForkExec with the Ptrace flag enabled - my expectation of this flag is that it enables tracing syscalls of the child process after the fork has occurred, something like the following (as I would write, if implementing the same program in C):

pid = fork();
switch( pid )
{
    // Error
    case -1:
    {
        printf( "Fork failed!" );
        break
    }

    // Child process.
    case 0:
    {
        // Enable tracing of this process.
        ptrace( PTRACE_TRACEME, 0, 0, 0 );

        // SIGSTOP to allow parent to catch all syscalls from execvp() onwards.
        kill( getpid(), SIGSTOP );
        return execvp( args[0], args );
    }

    // Parent process.
    default:
    {
        // Wait for child to SIGSTOP.
        waitpid( pid, &status, 0 );
        assert( WIFSTOPPED( status ) );

        // Set ptrace options.
        ptrace( PTRACE_SETOPTIONS, pid, 0, PTRACE_O_TRACESYSGOOD );

        // Child is currently entering a kill() syscall - restart and catch the exit of that syscall.
        ptrace( PTRACE_SYSCALL, pid, 0, 0 );
        waitpid( pid, &status, 0 );

        // Child is about to execvp() - start tracing...
        trace( pid );        
    }
}

void trace( int pid )
{
    // Loop until child exits.
    while( 1 )
    {
        // Restart child and wait for next syscall entry.
        ptrace( PTRACE_SYSCALL, pid, 0, 0 );
        waitpid( pid, &status, 0);

        // Check status for child exiting.
        ...

        // Print syscall entry details.
        ...

        // Restart child and wait for syscall exit.
        ptrace( PTRACE_SYSCALL, pid, 0, 0 );
        waitpid( pid, &status, 0 );

        // Check status for child exiting.
        ...

        // Print syscall exit (retval) details.
        ...
    }
}

However it doesn't seem like the above is possible in Go due to the fact that the Ptrace flag is checked too early in https://golang.org/src/syscall/exec_linux.go (forkAndExecInChild()) and a number of (Go runtime) syscalls are performed between enabling tracing and the actual exec call.

Here's a cut-down version of the code I'm using:

// Create process attributes.
attr := syscall.ProcAttr{
    ...
    Sys: &syscall.SysProcAttr{
        Ptrace:  true,
    },
}

// Fork/exec command.
pid, err := syscall.ForkExec( path, args, &attr )
...

// Wait on child.
var wstat syscall.WaitStatus
_, err = syscall.Wait4( pid, &wstat, 0, nil )
...

// Set Ptrace options
err = syscall.PtraceSetOptions( pid, syscall.PTRACE_O_TRACESYSGOOD )

// Trace child...
trace( pid )



func trace {

    for {
        // Restart child and wait for next syscall entry.
        err := syscall.PtraceSyscall( pid, 0 )
        ...
        var wstat syscall.WaitStatus
        _, err = syscall.Wait4( pid, &wstat, 0, nil )
        ...

        // Check status for child exiting.
        ...

        // Print syscall entry details.
        ...

        // Restart child and wait for next syscall entry.
        err := syscall.PtraceSyscall( pid, 0 )
        ...
        var wstat syscall.WaitStatus
        _, err = syscall.Wait4( pid, &wstat, 0, nil )
        ...

        // Check status for child exiting.
        ...

        // Print syscall exit (retval) details.
        ...
    }
}

Question

Why was this design decision made and what is the intended usage of the Ptrace flag? Is it the intended behaviour to trace the Go runtime in the child process before the exec? If so, that's a bit counter-intuitive to the user.

Even better, is there a code example demonstrating the intended usage of the Ptrace flag and how one might implement strace using Go?

@odeke-em odeke-em changed the title from syscall.ForkExec with Ptrace flag causes Go runtime to be traced to syscall: ForkExec with Ptrace flag causes runtime to be traced Aug 14, 2017

@odeke-em

This comment has been minimized.

Show comment
Hide comment
@odeke-em

odeke-em Aug 14, 2017

Member

@bjames2011 there was a presentation at Gophercon by Liz Rice @lizrice at https://medium.com/@lizrice/strace-in-60-lines-of-go-b4b76e3ecd64 "Strace in 60 lines of Go", that might help you.

Member

odeke-em commented Aug 14, 2017

@bjames2011 there was a presentation at Gophercon by Liz Rice @lizrice at https://medium.com/@lizrice/strace-in-60-lines-of-go-b4b76e3ecd64 "Strace in 60 lines of Go", that might help you.

@ianlancetaylor ianlancetaylor added this to the Go1.10 milestone Aug 14, 2017

@ianlancetaylor

This comment has been minimized.

Show comment
Hide comment
@ianlancetaylor

ianlancetaylor Aug 14, 2017

Contributor

It's true that there are various optional system calls that may be executed after the ptrace system call, but it's not obvious to me why that matters one way or another.

For what it's worth, it's unusually to call syscall.ForkExec directly. Normally people call os.StartProcess or use the os/exec package. But I don't know whether that makes a difference here.

What fix do you suggest? To simply move the ptrace system call down to just before the execve system call?

Contributor

ianlancetaylor commented Aug 14, 2017

It's true that there are various optional system calls that may be executed after the ptrace system call, but it's not obvious to me why that matters one way or another.

For what it's worth, it's unusually to call syscall.ForkExec directly. Normally people call os.StartProcess or use the os/exec package. But I don't know whether that makes a difference here.

What fix do you suggest? To simply move the ptrace system call down to just before the execve system call?

@bjames2011

This comment has been minimized.

Show comment
Hide comment
@bjames2011

bjames2011 Aug 14, 2017

@bjames2011 there was a presentation at Gophercon by Liz Rice @lizrice at https://medium.com/@lizrice/strace-in-60-lines-of-go-b4b76e3ecd64 "Strace in 60 lines of Go", that might help you.

Thanks; for some reason, I'd completely failed to find anything like this when Googling. The code in that presentation is very similar to what I ended up with - albeit using os.StartProcess() instead of syscall.ForkExec().

but it's not obvious to me why that matters one way or another

Hence my intro text "This is somewhat of a philosophical question about the design decisions made in the Go runtime, rather than a bug, per-se."

It is somewhat counter-intuitive, when tracing a process, to see completely unrelated system calls not executed by the process. From a user point-of-view, what the runtime does in order to set up the new process is completely unrelated to the process itself (and simply a side-effect of the fact that we're writing Go).

After all, the only way to know which syscalls were executed by the subprocess - rather than the Go runtime - is to track the syscall type and ignore all syscalls until the execve(), however this makes the code rather ugly (and makes it very obvious that you're "working around" an idiosyncrasy of the runtime). Such a work-around also exposes implementation details of the Go runtime and would need to be updated if the runtime decided to use a different member of the exec*() family, for example.

What fix do you suggest? To simply move the ptrace system call down to just before the execve system call?

That's exactly what I was implying with my C example. ;-)

Unless there was a conscious design decision made to include the Go runtime calls in the trace (and I can't see any logical reason why this would make sense), I would very much suggest moving the ptrace() down to the line immediately before the execve() - this would fix this issue.

If you need further justification, it would also be a moral victory (as you will have converted one more C programmer to using Go, as - at present - I've rewritten my program in C).

bjames2011 commented Aug 14, 2017

@bjames2011 there was a presentation at Gophercon by Liz Rice @lizrice at https://medium.com/@lizrice/strace-in-60-lines-of-go-b4b76e3ecd64 "Strace in 60 lines of Go", that might help you.

Thanks; for some reason, I'd completely failed to find anything like this when Googling. The code in that presentation is very similar to what I ended up with - albeit using os.StartProcess() instead of syscall.ForkExec().

but it's not obvious to me why that matters one way or another

Hence my intro text "This is somewhat of a philosophical question about the design decisions made in the Go runtime, rather than a bug, per-se."

It is somewhat counter-intuitive, when tracing a process, to see completely unrelated system calls not executed by the process. From a user point-of-view, what the runtime does in order to set up the new process is completely unrelated to the process itself (and simply a side-effect of the fact that we're writing Go).

After all, the only way to know which syscalls were executed by the subprocess - rather than the Go runtime - is to track the syscall type and ignore all syscalls until the execve(), however this makes the code rather ugly (and makes it very obvious that you're "working around" an idiosyncrasy of the runtime). Such a work-around also exposes implementation details of the Go runtime and would need to be updated if the runtime decided to use a different member of the exec*() family, for example.

What fix do you suggest? To simply move the ptrace system call down to just before the execve system call?

That's exactly what I was implying with my C example. ;-)

Unless there was a conscious design decision made to include the Go runtime calls in the trace (and I can't see any logical reason why this would make sense), I would very much suggest moving the ptrace() down to the line immediately before the execve() - this would fix this issue.

If you need further justification, it would also be a moral victory (as you will have converted one more C programmer to using Go, as - at present - I've rewritten my program in C).

@lizrice

This comment has been minimized.

Show comment
Hide comment
@lizrice

lizrice Aug 14, 2017

Thanks for the shout-out @odeke-em :-)

Just reading the source quickly there, the Ptrace flag is checked as soon as the Clone syscall creates the child process. So yes, it's tracing the syscalls that the Go runtime calls before the execve, but they are executed by the child process - so I think it's right that they are included in the trace. If the ptrace wasn't started until just before the execve, I think we'd just lose the ability to trace those syscalls, wouldn't we?

lizrice commented Aug 14, 2017

Thanks for the shout-out @odeke-em :-)

Just reading the source quickly there, the Ptrace flag is checked as soon as the Clone syscall creates the child process. So yes, it's tracing the syscalls that the Go runtime calls before the execve, but they are executed by the child process - so I think it's right that they are included in the trace. If the ptrace wasn't started until just before the execve, I think we'd just lose the ability to trace those syscalls, wouldn't we?

@bjames2011

This comment has been minimized.

Show comment
Hide comment
@bjames2011

bjames2011 Aug 14, 2017

...but they are executed by the child process - so I think it's right that they are included in the trace.

Yes, they are executed by the child process, but not by the program that the user specified in the call to os.Command(), but instead by the runtime.

If the ptrace wasn't started until just before the execve, I think we'd just lose the ability to trace those syscalls, wouldn't we?

Yes, but all the syscalls executed before the exec are completely unrelated to the thing the user asked to trace. In this case, the user API exposes "trace this program" (n.b. the forked process is just a side-effect of how the program is run), but the outcome is "trace this program (and some unexpected stuff the runtime decides to do)".

A few points here:

  1. If you decide to change the runtime, it will appear to the user as if the child program (which may well be completely unchanged) has mysteriously changed its behaviour.
  2. Even though you lose the ability to trace the process syscalls before the execve, there is no information lost here - all the syscalls before the execve are a result of the data passed by the user anyway.

I can't think of a use-case where the user of this API would want to trace the runtime implicitly like this; the only time it would make sense to trace those runtime syscalls would be from an external process (i.e. a debugger attaching to the parent Go process) and in that case, the suggested change would not cause any syscalls to be lost.

Overall, I'd say that the current behaviour falls into the realm of "exposing the implementation" and the suggested change should be considered.

bjames2011 commented Aug 14, 2017

...but they are executed by the child process - so I think it's right that they are included in the trace.

Yes, they are executed by the child process, but not by the program that the user specified in the call to os.Command(), but instead by the runtime.

If the ptrace wasn't started until just before the execve, I think we'd just lose the ability to trace those syscalls, wouldn't we?

Yes, but all the syscalls executed before the exec are completely unrelated to the thing the user asked to trace. In this case, the user API exposes "trace this program" (n.b. the forked process is just a side-effect of how the program is run), but the outcome is "trace this program (and some unexpected stuff the runtime decides to do)".

A few points here:

  1. If you decide to change the runtime, it will appear to the user as if the child program (which may well be completely unchanged) has mysteriously changed its behaviour.
  2. Even though you lose the ability to trace the process syscalls before the execve, there is no information lost here - all the syscalls before the execve are a result of the data passed by the user anyway.

I can't think of a use-case where the user of this API would want to trace the runtime implicitly like this; the only time it would make sense to trace those runtime syscalls would be from an external process (i.e. a debugger attaching to the parent Go process) and in that case, the suggested change would not cause any syscalls to be lost.

Overall, I'd say that the current behaviour falls into the realm of "exposing the implementation" and the suggested change should be considered.

@bjames2011

This comment has been minimized.

Show comment
Hide comment
@bjames2011

bjames2011 Aug 14, 2017

Also, the "missing syscalls" argument has a hole in it as there are other syscalls between the fork() and the ptrace() which won't be caught (from: https://golang.org/src/syscall/exec_linux.go):

...
	// Fork succeeded, now in child.
  
  	// Wait for User ID/Group ID mappings to be written.
  	if sys.UidMappings != nil || sys.GidMappings != nil {
  		if _, _, err1 = RawSyscall(SYS_CLOSE, uintptr(p[1]), 0, 0); err1 != 0 {
  			goto childerror
  		}
  		r1, _, err1 = RawSyscall(SYS_READ, uintptr(p[0]), uintptr(unsafe.Pointer(&err2)), unsafe.Sizeof(err2))
  		if err1 != 0 {
  			goto childerror
  		}
  		if r1 != unsafe.Sizeof(err2) {
  			err1 = EINVAL
  			goto childerror
  		}
  		if err2 != 0 {
  			err1 = err2
  			goto childerror
  		}
  	}
  
  	// Enable tracing if requested.
  	if sys.Ptrace {
  		_, _, err1 = RawSyscall(SYS_PTRACE, uintptr(PTRACE_TRACEME), 0, 0)
  		if err1 != 0 {
  			goto childerror
  		}
  	}
...

bjames2011 commented Aug 14, 2017

Also, the "missing syscalls" argument has a hole in it as there are other syscalls between the fork() and the ptrace() which won't be caught (from: https://golang.org/src/syscall/exec_linux.go):

...
	// Fork succeeded, now in child.
  
  	// Wait for User ID/Group ID mappings to be written.
  	if sys.UidMappings != nil || sys.GidMappings != nil {
  		if _, _, err1 = RawSyscall(SYS_CLOSE, uintptr(p[1]), 0, 0); err1 != 0 {
  			goto childerror
  		}
  		r1, _, err1 = RawSyscall(SYS_READ, uintptr(p[0]), uintptr(unsafe.Pointer(&err2)), unsafe.Sizeof(err2))
  		if err1 != 0 {
  			goto childerror
  		}
  		if r1 != unsafe.Sizeof(err2) {
  			err1 = EINVAL
  			goto childerror
  		}
  		if err2 != 0 {
  			err1 = err2
  			goto childerror
  		}
  	}
  
  	// Enable tracing if requested.
  	if sys.Ptrace {
  		_, _, err1 = RawSyscall(SYS_PTRACE, uintptr(PTRACE_TRACEME), 0, 0)
  		if err1 != 0 {
  			goto childerror
  		}
  	}
...
@lizrice

This comment has been minimized.

Show comment
Hide comment
@lizrice

lizrice Aug 15, 2017

fwiw I agree with you that the call to SYS_PTRACE is either too early or too late (and without checking the history, I'd bet that that the UID/GID mappings section was added more recently.)

@ianlancetaylor pretty sure that os.StartProcess() ends up calling syscall.ForkExec() anyway, so would result in the same behaviour

lizrice commented Aug 15, 2017

fwiw I agree with you that the call to SYS_PTRACE is either too early or too late (and without checking the history, I'd bet that that the UID/GID mappings section was added more recently.)

@ianlancetaylor pretty sure that os.StartProcess() ends up calling syscall.ForkExec() anyway, so would result in the same behaviour

@ianlancetaylor

This comment has been minimized.

Show comment
Hide comment
@ianlancetaylor

ianlancetaylor Aug 15, 2017

Contributor

I have no opinion on the right fix. Does somebody want to send in a change?

Contributor

ianlancetaylor commented Aug 15, 2017

I have no opinion on the right fix. Does somebody want to send in a change?

@jessfraz

This comment has been minimized.

Show comment
Hide comment
@jessfraz

jessfraz Aug 15, 2017

Contributor

I can send a patch to move the ptrace call before execve

Contributor

jessfraz commented Aug 15, 2017

I can send a patch to move the ptrace call before execve

@gopherbot

This comment has been minimized.

Show comment
Hide comment
@gopherbot

gopherbot Aug 15, 2017

Change https://golang.org/cl/55811 mentions this issue: syscall: move ptrace setup to right before exec

gopherbot commented Aug 15, 2017

Change https://golang.org/cl/55811 mentions this issue: syscall: move ptrace setup to right before exec

@ianlancetaylor

This comment has been minimized.

Show comment
Hide comment
@ianlancetaylor

ianlancetaylor Aug 15, 2017

Contributor

@jessfraz Thanks. Does anybody who cares about this issue object to https://golang.org/cl/55811?

Contributor

ianlancetaylor commented Aug 15, 2017

@jessfraz Thanks. Does anybody who cares about this issue object to https://golang.org/cl/55811?

@lizrice

This comment has been minimized.

Show comment
Hide comment
@lizrice

lizrice Aug 15, 2017

don't know how qualified I am to say this, but lgtm!

lizrice commented Aug 15, 2017

don't know how qualified I am to say this, but lgtm!

@odeke-em

This comment has been minimized.

Show comment
Hide comment
@odeke-em

odeke-em Aug 15, 2017

Member

@lizrice I don't know if you are interested, but if you can log into Gerrit with a gmail account, it'd be awesome to have you there as a reviewer and you can put your approvals or disapprovals on there, and then in merges, yours will be there on the record as a Go reviewer!

Member

odeke-em commented Aug 15, 2017

@lizrice I don't know if you are interested, but if you can log into Gerrit with a gmail account, it'd be awesome to have you there as a reviewer and you can put your approvals or disapprovals on there, and then in merges, yours will be there on the record as a Go reviewer!

@bjames2011

This comment has been minimized.

Show comment
Hide comment
@bjames2011

bjames2011 Aug 15, 2017

The review looks good to me. Thanks to everyone on the quick responses so far.

bjames2011 commented Aug 15, 2017

The review looks good to me. Thanks to everyone on the quick responses so far.

@odeke-em

This comment has been minimized.

Show comment
Hide comment
@odeke-em

odeke-em Aug 15, 2017

Member

Same thing for you too @bjames2011 as I had mentioned in #21428 (comment) :)

Member

odeke-em commented Aug 15, 2017

Same thing for you too @bjames2011 as I had mentioned in #21428 (comment) :)

@lizrice

This comment has been minimized.

Show comment
Hide comment
@lizrice

lizrice Aug 15, 2017

Thanks @odeke-em - I added myself as a reviewer on there. Exciting, my first Go review is a LGTM on a @jessfraz change :-)

lizrice commented Aug 15, 2017

Thanks @odeke-em - I added myself as a reviewer on there. Exciting, my first Go review is a LGTM on a @jessfraz change :-)

@jessfraz

This comment has been minimized.

Show comment
Hide comment
@jessfraz

jessfraz Aug 15, 2017

Contributor
Contributor

jessfraz commented Aug 15, 2017

@gopherbot gopherbot closed this in e974f4f Aug 23, 2017

@golang golang locked and limited conversation to collaborators Aug 23, 2018

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.