Skip to content

os/exec: understand 387 fd leak #7808

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.

Sign up for GitHub

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

Jump to bottom
Closed
bradfitz opened this issue Apr 17, 2014 · 14 comments
Closed

os/exec: understand 387 fd leak #7808

bradfitz opened this issue Apr 17, 2014 · 14 comments
Labels
FrozenDueToAge
Milestone
Go1.3

Comments

@bradfitz
Copy link
Contributor 

The linux-386-387 builder continues to fail somewhat regularly with:

--- FAIL: TestPipeLookPathLeak (0.07 seconds)
    exec_test.go:230: leaked 4 fds; want ~0; have:
        COMMAND    PID    USER   FD   TYPE DEVICE SIZE/OFF    NODE NAME
        exec.test 2220 gobuild  cwd    DIR  202,1     4096  288319 /tmp/gobuilder/linux-386-387-0c830eabe9d2/go/src/pkg/os/exec
        exec.test 2220 gobuild  rtd    DIR  202,1     4096       2 /
        exec.test 2220 gobuild  txt    REG  202,1  4322404  167545 /tmp/go-build844875145/os/exec/_test/exec.test
        exec.test 2220 gobuild  mem    REG  202,1  1779492  394095 /lib/i386-linux-gnu/tls/i686/nosegneg/libc-2.17.so
        exec.test 2220 gobuild  mem    REG  202,1   125343  394109 /lib/i386-linux-gnu/tls/i686/nosegneg/libpthread-2.17.so
        exec.test 2220 gobuild  mem    REG  202,1   134376  393742 /lib/i386-linux-gnu/ld-2.17.so
        exec.test 2220 gobuild    0r   CHR    1,3      0t0    5576 /dev/null
        exec.test 2220 gobuild    1w  FIFO    0,8      0t0 5751814 pipe
        exec.test 2220 gobuild    2w  FIFO    0,8      0t0 5751814 pipe
        exec.test 2220 gobuild    3r   CHR    1,3      0t0    5576 /dev/null
        exec.test 2220 gobuild    4r  FIFO    0,8      0t0 5751900 pipe
        exec.test 2220 gobuild    5w  FIFO    0,8      0t0 5751900 pipe
        exec.test 2220 gobuild    6w   CHR    1,3      0t0    5576 /dev/null
        exec.test 2220 gobuild    7r  FIFO    0,8      0t0 5751901 pipe
        
        originally:
        COMMAND    PID    USER   FD   TYPE DEVICE SIZE/OFF    NODE NAME
        exec.test 2220 gobuild  cwd    DIR  202,1     4096  288319 /tmp/gobuilder/linux-386-387-0c830eabe9d2/go/src/pkg/os/exec
        exec.test 2220 gobuild  rtd    DIR  202,1     4096       2 /
        exec.test 2220 gobuild  txt    REG  202,1  4322404  167545 /tmp/go-build844875145/os/exec/_test/exec.test
        exec.test 2220 gobuild  mem    REG  202,1  1779492  394095 /lib/i386-linux-gnu/tls/i686/nosegneg/libc-2.17.so
        exec.test 2220 gobuild  mem    REG  202,1   125343  394109 /lib/i386-linux-gnu/tls/i686/nosegneg/libpthread-2.17.so
        exec.test 2220 gobuild  mem    REG  202,1   134376  393742 /lib/i386-linux-gnu/ld-2.17.so
        exec.test 2220 gobuild    0r   CHR    1,3      0t0    5576 /dev/null
        exec.test 2220 gobuild    1w  FIFO    0,8      0t0 5751814 pipe
        exec.test 2220 gobuild    2w  FIFO    0,8      0t0 5751814 pipe
        exec.test 2220 gobuild    4r  FIFO    0,8      0t0 5751857 pipe
FAIL



Why?

Why only this builder?
@ianlancetaylor
Copy link
Member

Comment 1:

It looks like the extra pipes are two read pipes and one write pipe, which suggests that
they are the parent descriptors (reading from stdout and stderr, writing to stdin). 
Unfortunately that makes no sense at all since those are explicitly closed.

@bradfitz
Copy link
Contributor Author

Comment 2:

I can reproduce this on that builder if anybody has theories for me to try.

@ianlancetaylor
Copy link
Member

Comment 3:

Try changing os/pipe_linux.go to always use Pipe and CloseOnExec, rather than Pipe2.  As
far as I can tell that can not be the problem, but at the same time I can't see of any
other possibility.

@bradfitz
Copy link
Contributor Author

Comment 4:

Nope, that doesn't fix it.
 
Also, I can reproduce on the same machine with GO386 unset (normal linux/386 mode).
Machine details, on EC2:
Linux gobuilder387 3.11.0-15-generic #25-Ubuntu SMP Thu Jan 30 17:25:07 UTC 2014 i686
i686 i686 GNU/Linux
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=13.10
DISTRIB_CODENAME=saucy
DISTRIB_DESCRIPTION="Ubuntu 13.10"
$ cat /proc/cpuinfo 
processor   : 0
vendor_id   : GenuineIntel
cpu family  : 6
model       : 23
model name  : Intel(R) Xeon(R) CPU           E5430  @ 2.66GHz
stepping    : 10
microcode   : 0xa07
cpu MHz     : 2659.994
cache size  : 6144 KB
fdiv_bug    : no
f00f_bug    : no
coma_bug    : no
fpu     : yes
fpu_exception   : yes
cpuid level : 13
wp      : yes
flags       : fpu tsc msr pae mce cx8 mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht
pbe nx lm constant_tsc arch_perfmon pebs bts pni dtes64 monitor ds_cpl vmx est tm2 ssse3
cx16 xtpr pdcm dca sse4_1 lahf_lm dtherm tpr_shadow vnmi flexpriority
bogomips    : 5319.98
clflush size    : 64
cache_alignment : 64
address sizes   : 38 bits physical, 48 bits virtual
power management:

@alberts
Copy link
Contributor

alberts commented Apr 18, 2014

Comment 5:

I've seen races before where we managed to find files and directories in /proc even
after system calls that would let you think that they should be gone have returned.
Could lsof be picking up just-closed file descriptors when reading /proc?

@bradfitz
Copy link
Contributor Author

Comment 6:

Good theory.
I'm running now with GC disabled for that function (so no possibility of finalizers
closing the fds) and putting in a small sleep before the lsof check.
At 50 ms, I still saw a crash after a long run.
I'll collect some more numbers with different sleep intervals and see if a bigger sleep
causes a smaller percentage of failures.

@bradfitz
Copy link
Contributor Author

Comment 7:

Seems like it's proc being slow.
I'll make the test more robust.

Owner changed to @bradfitz.

@bradfitz
Copy link
Contributor Author

Comment 8:

For the record, I also tried disabling GC to rule out Go's finalizers closing fds. It
really does appear that Linux's /proc is only eventually consistent.
CL coming.

@gopherbot
Copy link
Contributor

Comment 9:

CL https://golang.org/cl/90400044 mentions this issue.

@bradfitz
Copy link
Contributor Author

Comment 10:

This issue was closed by revision 5600572.

Status changed to Fixed.

@bradfitz bradfitz self-assigned this Apr 23, 2014
@rsc rsc added this to the Go1.3 milestone Apr 14, 2015
@pjbgtnj
Copy link

pjbgtnj commented Feb 9, 2016

I'm current having the issue on build -> go version devel +79d9f48 Tue Feb 9 21:12:32 2016 +0000 linux/amd64
If I change the wait from 100ms to 1 second on line 837 of exec_test.go, it will pass the test. Otherwise the test fails with 4 leaked fds.

@bradfitz
Copy link
Contributor Author

bradfitz commented Feb 9, 2016

@pjbgtnj, this is the wrong place for this discussion. This bug was closed years ago. We do not use old issues. It's not even the same issue.

@pjbgtnj
Copy link

pjbgtnj commented Feb 10, 2016

Brad,

Sorry - I'm new to this process and not sure where to respond to issues.
This is the error I sometimes get when compiling and the comment in the
code led me to that issue. What should I have correctly done?

ok os 0.273s
--- FAIL: TestPipeLookPathLeak (0.49s)
exec_test.go:244: leaked 4 fds; want ~0; have:
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
exec.test 24880 auser cwd DIR 8,3 4096 3961650
/home/auser/Downloads/go/src/os/exec
exec.test 24880 auser rtd DIR 8,3 4096 128 /
exec.test 24880 auser txt REG 8,3 6917325 136616068
/tmp/go-build576697898/os/exec/_test/exec.test
exec.test 24880 auser mem REG 8,3 2107816 134459016 /usr/lib64/
libc-2.17.so
exec.test 24880 auser mem REG 8,3 142304 134459042 /usr/lib64/
libpthread-2.17.so
exec.test 24880 auser mem REG 8,3 164440 134524393 /usr/lib64/
ld-2.17.so
exec.test 24880 auser 0r CHR 1,3 0t0 1028 /dev/null
exec.test 24880 auser 1w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 2w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 3r CHR 1,3 0t0 1028 /dev/null
exec.test 24880 auser 4r FIFO 0,8 0t0 90890 pipe
exec.test 24880 auser 5w FIFO 0,8 0t0 90890 pipe
exec.test 24880 auser 6r FIFO 0,8 0t0 90891 pipe
exec.test 24880 auser 7w FIFO 0,8 0t0 90891 pipe
exec.test 24880 auser 8r FIFO 0,8 0t0 90892 pipe
originally:
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
exec.test 24880 auser cwd DIR 8,3 4096 3961650
/home/auser/Downloads/go/src/os/exec
exec.test 24880 auser rtd DIR 8,3 4096 128 /
exec.test 24880 auser txt REG 8,3 6917325 136616068
/tmp/go-build576697898/os/exec/_test/exec.test
exec.test 24880 auser mem REG 8,3 2107816 134459016 /usr/lib64/
libc-2.17.so
exec.test 24880 auser mem REG 8,3 142304 134459042 /usr/lib64/
libpthread-2.17.so
exec.test 24880 auser mem REG 8,3 164440 134524393 /usr/lib64/
ld-2.17.so
exec.test 24880 auser 0r CHR 1,3 0t0 1028 /dev/null
exec.test 24880 auser 1w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 2w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 4r FIFO 0,8 0t0 90788 pipe
exec.test 24880 auser 6r FIFO 0,8 0t0 90789 pipe
FAIL
FAIL os/exec 0.616s

On Tue, Feb 9, 2016 at 5:06 PM, Brad Fitzpatrick notifications@github.com
wrote:

@pjbgtnj https://github.com/pjbgtnj, this is the wrong place for this
discussion. This bug was closed years ago. We do not use old issues. It's
not even the same issue.

—
Reply to this email directly or view it on GitHub
#7808 (comment).

@davecheney
Copy link
Contributor

Please open a new issue

On Wed, 10 Feb 2016, 22:36 pjbgtnj notifications@github.com wrote:

Brad,

Sorry - I'm new to this process and not sure where to respond to issues.
This is the error I sometimes get when compiling and the comment in the
code led me to that issue. What should I have correctly done?

ok os 0.273s
--- FAIL: TestPipeLookPathLeak (0.49s)
exec_test.go:244: leaked 4 fds; want ~0; have:
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
exec.test 24880 auser cwd DIR 8,3 4096 3961650
/home/auser/Downloads/go/src/os/exec
exec.test 24880 auser rtd DIR 8,3 4096 128 /
exec.test 24880 auser txt REG 8,3 6917325 136616068
/tmp/go-build576697898/os/exec/_test/exec.test
exec.test 24880 auser mem REG 8,3 2107816 134459016 /usr/lib64/
libc-2.17.so
exec.test 24880 auser mem REG 8,3 142304 134459042 /usr/lib64/
libpthread-2.17.so
exec.test 24880 auser mem REG 8,3 164440 134524393 /usr/lib64/
ld-2.17.so
exec.test 24880 auser 0r CHR 1,3 0t0 1028 /dev/null
exec.test 24880 auser 1w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 2w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 3r CHR 1,3 0t0 1028 /dev/null
exec.test 24880 auser 4r FIFO 0,8 0t0 90890 pipe
exec.test 24880 auser 5w FIFO 0,8 0t0 90890 pipe
exec.test 24880 auser 6r FIFO 0,8 0t0 90891 pipe
exec.test 24880 auser 7w FIFO 0,8 0t0 90891 pipe
exec.test 24880 auser 8r FIFO 0,8 0t0 90892 pipe
originally:
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
exec.test 24880 auser cwd DIR 8,3 4096 3961650
/home/auser/Downloads/go/src/os/exec
exec.test 24880 auser rtd DIR 8,3 4096 128 /
exec.test 24880 auser txt REG 8,3 6917325 136616068
/tmp/go-build576697898/os/exec/_test/exec.test
exec.test 24880 auser mem REG 8,3 2107816 134459016 /usr/lib64/
libc-2.17.so
exec.test 24880 auser mem REG 8,3 142304 134459042 /usr/lib64/
libpthread-2.17.so
exec.test 24880 auser mem REG 8,3 164440 134524393 /usr/lib64/
ld-2.17.so
exec.test 24880 auser 0r CHR 1,3 0t0 1028 /dev/null
exec.test 24880 auser 1w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 2w FIFO 0,8 0t0 90742 pipe
exec.test 24880 auser 4r FIFO 0,8 0t0 90788 pipe
exec.test 24880 auser 6r FIFO 0,8 0t0 90789 pipe
FAIL
FAIL os/exec 0.616s

On Tue, Feb 9, 2016 at 5:06 PM, Brad Fitzpatrick <notifications@github.com

wrote:

@pjbgtnj https://github.com/pjbgtnj, this is the wrong place for this
discussion. This bug was closed years ago. We do not use old issues. It's
not even the same issue.

—
Reply to this email directly or view it on GitHub
#7808 (comment).

—
Reply to this email directly or view it on GitHub
#7808 (comment).

@golang golang locked and limited conversation to collaborators Feb 10, 2016
This issue was closed.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
Go1.3
Development

No branches or pull requests
7 participants
@bradfitz @davecheney @rsc @alberts @ianlancetaylor @gopherbot @pjbgtnj