Re: libgo patch committed: Update to current Go library

[Ian Lance Taylor <iant at google dot com>]

On Wed, Oct 24, 2012 at 6:19 AM, Uros Bizjak <ubizjak@gmail.com> wrote:
> On Wed, Oct 24, 2012 at 3:10 PM, Ian Lance Taylor <iant@google.com> wrote:
>> On Wed, Oct 24, 2012 at 5:31 AM, Uros Bizjak <ubizjak@gmail.com> wrote:
>>> On Wed, Oct 24, 2012 at 2:18 PM, Andreas Schwab <schwab@linux-m68k.org> wrote:
>>>> Uros Bizjak <ubizjak@gmail.com> writes:
>>>>
>>>>> To answer my own question:
>>>>>
>>>>> dup(4)                                  = 9
>>>>> ...
>>>>> close(9)                                = 0
>>>>> dup(4)                                  = -1 EBADF (Bad file descriptor)
>>>>>
>>>>> Test is calling dup on a closed file descriptor.
>>>>
>>>> FD 4 is most likely closed by one of the cloned threads.  Use strace -f
>>>> to follow them.
>>>
>>> Yes, indeed! Attached strace -f record confirms this on alpha.
>>>
>>> The same happens on x86_64, but for some reason x86_64 doesn't
>>> complain when executing dup(2) on closed FD.
>>
>> The test execs itself by calling the fork and execve functions in
>> libc.  It is the child process that closes the FD after it forks.
>> From the point of view of the parent process, the FD should still be
>> open.  I don't think you attached the strace -f output so I can't
>> confirm this.
>
> Eh, sorry, attached now.
>
> After the second socketpair and before dup, there is a close in the same thread.

Thanks.  I agree.  Unfortunately, I can't figure out what is causing
it.  These seem to be the relevant calls.

16252 socketpair(PF_FILE, SOCK_STREAM, 0, [3, 4]) = 0

16252 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x20002f0ecd0) = 16259

16259 execve("./a.out", ["./a.out", "-test.run=^TestPassFD$", "--",
"/tmp/TestPassFD684357043"], [/* 33 vars */] <unfinished ...>

16252 clone( <unfinished ...>
16252 <... clone resumed> child_stack=0x200031e2b70,
flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID,
parent_tidptr=0x200031e3350, tls=0x200031e3970,
child_tidptr=0x200031e3350) = 16260

***** This is the bad call, but where does this come from?
16252 close(4 <unfinished ...>
16252 <... close resumed> )             = 0

16260 wait4(16259,  <unfinished ...>

16261 read(9,  <unfinished ...>

16259 sendmsg(5, {msg_name(0)=NULL, msg_iov(1)=[{"x", 1}],
msg_controllen=24, {cmsg_len=20, cmsg_level=SOL_SOCKET,
cmsg_type=SCM_RIGHTS, {9}}, msg_flags=0}, 0) = 1

16259 exit_group(0)                     = ?

16261 <... read resumed> "", 512)       = 0

16260 <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0,
{ru_utime={0, 46875}, ru_stime={0, 26367}, ...}) = 16259

16261 dup(4)                            = -1 EBADF (Bad file descriptor)


Here is an approachj that might help.  Set a breakpoint on socketpair.
 The failure comes after the second call to socketpair, the one from
the function TestPassFD.  After that breakpoint is reached, set a
breakpoint on close.  Look for the call to close(4).  Get a backtrace
from there so we can see what is calling it.

Ian