os/exec always fails with fork/exec /usr/bin/qemu-img: invalid argument

[Tashi Lu]

Hi gophers,

I faced a strange problem： os/exec always fails with `fork/exec /usr/bin/qemu-img: invalid argument'. 

Simplified code is at https://play.golang.org/p/v1APfzmS2p9. It seems this simplified snippet runs well without errors, but my real code is no more than just some variable initializations than this snippet. So I suspect it's the context's problem, but my context is too complex to simplify and put onto the playground. What I can think of that what might be linked to this error is that this function is run in a goroutine. But I did write a simplified goroutine version, sadly it worked well too... I had no idea how to do further debugging.

And further, the executable is not to blame, it fails with the same error even if I substitute the executable to `ls' or anything else.

Can you provide me some suggestions to the possible reason or the way to debug? Thanks.

OS: centos 3.10.0-693.el7.x86_64

go env:

GOARCH="amd64"

GOBIN=""

GOEXE=""

GOHOSTARCH="amd64"

GOHOSTOS="linux"

GOOS="linux"

GOPATH="/root/go"

GORACE=""

GOROOT="/usr/lib/golang"

GOTOOLDIR="/usr/lib/golang/pkg/tool/linux_amd64"

GCCGO="/usr/bin/gccgo"

CC="gcc"

GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build942780360=/tmp/go-build -gno-record-gcc-switches"

CXX="g++"

CGO_ENABLED="1"

PKG_CONFIG="pkg-config"

CGO_CFLAGS="-g -O2"

CGO_CPPFLAGS=""

CGO_CXXFLAGS="-g -O2"

CGO_FFLAGS="-g -O2"

CGO_LDFLAGS="-g -O2"

[Ian Lance Taylor]

On Fri, May 11, 2018 at 8:36 PM, Tashi Lu <dotsl...@gmail.com> wrote:
>
> I faced a strange problem： os/exec always fails with `fork/exec
> /usr/bin/qemu-img: invalid argument'.
>
> Simplified code is at https://play.golang.org/p/v1APfzmS2p9. It seems this
> simplified snippet runs well without errors, but my real code is no more
> than just some variable initializations than this snippet. So I suspect it's
> the context's problem, but my context is too complex to simplify and put
> onto the playground. What I can think of that what might be linked to this
> error is that this function is run in a goroutine. But I did write a
> simplified goroutine version, sadly it worked well too... I had no idea how
> to do further debugging.
>
> And further, the executable is not to blame, it fails with the same error
> even if I substitute the executable to `ls' or anything else.
>
> Can you provide me some suggestions to the possible reason or the way to
> debug? Thanks.

I would look first at the SysProcAttr field. Do you set that? Look
closely at the values.

If that doesn't help, run your failing program under strace -f and
look for the failing system call.

Ian

[Zhang Qiang]

Hi Ian,

Thanks for your valuable advice on debugging.

The SysProcAttr field is nil, and I can't see why it fails from the
strace, seems it just found the executable and then fails without
doing fork:

stat("/usr/bin/qemu-img", {st_mode=S_IFREG|0755, st_size=815784, ...}) = 0
write(1, "SysProcAttr: <nil>", 18SysProcAttr: <nil>) = 18
openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) = 7
pipe2([8, 9], O_CLOEXEC) = 0
pipe2([10, 11], O_CLOEXEC) = 0
close(7) = 0
close(9) = 0
close(11) = 0
close(8) = 0
close(10) = 0
write(1, "ret {\"status\":\"error\",\"error\":\"f"..., 79ret
{"status":"error","error":"fork/exec /usr/bin/qemu-img: invalid
argument"}

[Ian Lance Taylor]

On Fri, May 11, 2018 at 9:47 PM, Zhang Qiang <dotsl...@gmail.com> wrote:
>
> Thanks for your valuable advice on debugging.
>
> The SysProcAttr field is nil, and I can't see why it fails from the
> strace, seems it just found the executable and then fails without
> doing fork:
>
> stat("/usr/bin/qemu-img", {st_mode=S_IFREG|0755, st_size=815784, ...}) = 0
> write(1, "SysProcAttr: <nil>", 18SysProcAttr: <nil>) = 18
> openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) = 7
> pipe2([8, 9], O_CLOEXEC) = 0
> pipe2([10, 11], O_CLOEXEC) = 0
> close(7) = 0
> close(9) = 0
> close(11) = 0
> close(8) = 0
> close(10) = 0
> write(1, "ret {\"status\":\"error\",\"error\":\"f"..., 79ret
> {"status":"error","error":"fork/exec /usr/bin/qemu-img: invalid
> argument"}

Thanks. That looks like the output from strace, not strace -f.

Ian

[Zhang Qiang]

The -f output with more context(returning to the main thread 30617 and
waiting for another socket connection):

[pid 30670] clock_gettime(CLOCK_REALTIME, {1526142534, 664590192}) = 0
[pid 30670] write(2, "2018/05/13 00:28:54 cmd params c"...,
1492018/05/13 00:28:54 cmd params create -f qcow2
/data/kvm_img/b628579d-ae3d-41f0-887e-895204190c70/new-disk1.qcow2
1024M
) = 149
[pid 30670] stat("/usr/local/sbin/qemu-img", 0xc42005a6b8) = -1 ENOENT
(No such file or directory)
[pid 30670] stat("/usr/local/bin/qemu-img", 0xc42005a788) = -1 ENOENT
(No such file or directory)[pid 30670] stat("/usr/sbin/qemu-img",
0xc42005a858) = -1 ENOENT (No such file or directory)
[pid 30670] stat("/usr/bin/qemu-img", {st_mode=S_IFREG|0755,

st_size=815784, ...}) = 0

[pid 30670] openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) = 7
[pid 30670] pipe2([8, 9], O_CLOEXEC) = 0
[pid 30670] pipe2([10, 11], O_CLOEXEC) = 0
[pid 30670] close(7) = 0
[pid 30670] close(9) = 0
[pid 30670] close(11) = 0
[pid 30670] close(8) = 0
[pid 30670] close(10) = 0
[pid 30670] write(1, "ret {\"status\":\"error\",\"error\":\"f"...,

79ret {"status":"error","error":"fork/exec /usr/bin/qemu-img: invalid
argument"}

) = 79
[pid 30670] write(6, "{\"status\":\"error\",\"error\":\"fork/"..., 74) = 74
[pid 30670] write(1, "handle over, byebye\n", 20handle over, byebye
) = 20
[pid 30670] epoll_ctl(5, EPOLL_CTL_DEL, 6, 0xc42004ddec) = 0[pid
30670] close(6) = 0
[pid 30670] epoll_wait(5, [], 128, 0) = 0
[pid 30670] epoll_wait(5, <unfinished ...>
[pid 30671] <... sched_yield resumed> ) = 0
[pid 30671] futex(0x9fe610, FUTEX_WAKE, 1) = 0
[pid 30671] clock_gettime(CLOCK_MONOTONIC, {4411908, 247223972}) = 0
[pid 30671] clock_gettime(CLOCK_REALTIME, {1526142534, 671270292}) = 0
[pid 30671] pselect6(0, NULL, NULL, NULL, {0, 20000}, NULL) = 0 (Timeout)
[pid 30671] clock_gettime(CLOCK_MONOTONIC, {4411908, 247815618}) = 0
[pid 30671] futex(0x9fe6d8, FUTEX_WAIT, 0, {60, 0}

Still seems no fork though...

[Ian Lance Taylor]

Interesting. One possibility is that one of the arguments you are
passing to the process contains a NUL byte--a byte with the value 0.
That would cause this kind of error, as an argument with a NUL byte
can not be correctly passed to the kernel, which treats each argument
as ending at NUL.

Ian

[Matthias B.]

On Fri, 11 May 2018 20:36:18 -0700 (PDT)
Tashi Lu <dotsl...@gmail.com> wrote:

> Hi gophers,
>
> I faced a strange problem： os/exec always fails with `fork/exec
> /usr/bin/qemu-img: invalid argument'.
>
> Simplified code is at https://play.golang.org/p/v1APfzmS2p9. It seems
> this simplified snippet runs well without errors, but my real code is
> no more than just some variable initializations than this snippet. So
> I suspect it's the context's problem, but my context is too complex
> to simplify and put onto the playground. What I can think of that
> what might be linked to this error is that this function is run in a
> goroutine. But I did write a simplified goroutine version, sadly it
> worked well too... I had no idea how to do further debugging.
>
> And further, the executable is not to blame, it fails with the same
> error even if I substitute the executable to `ls' or anything else.

Try deleting the relevant lines of code and then write them again,
actually type them again, without referring to and especially not
copy'n'pasting code from somewhere else. Sounds stupid I know, but I've
given this advice many times over the years and it has an extremely
high success rate in the situation you're describing.

MSB

--
Light travels faster than sound. This is why some people appear bright
until you hear them speak.

[Zhang Qiang]

Hi Matthias,

Ian was right, the reason was the NUL bytes in the parameters. The
parameters were from a socket with extra NUL bytes and I forgot to
trim them.

Thanks for your advice anyway (:

> --
> You received this message because you are subscribed to a topic in the Google Groups "golang-nuts" group.
> To unsubscribe from this topic, visit https://groups.google.com/d/topic/golang-nuts/3aKF5NonPUc/unsubscribe.
> To unsubscribe from this group and all its topics, send an email to golang-nuts...@googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.