<div dir="ltr">Raimo,<br><br>Great work! You found it pretty quickly. I'll apply the patch as soon as possible.<br>I'll wait for a while before applying the patch to production systems until the regression tests are done.<br>
<br>Thanks very much.<br>Regards,<br>Edwin Fine<br><br><div class="gmail_quote">On Mon, Sep 15, 2008 at 10:54 AM, Raimo Niskanen <span dir="ltr"><<a href="mailto:raimo%2Berlang-bugs@erix.ericsson.se">raimo+erlang-bugs@erix.ericsson.se</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">On Mon, Sep 15, 2008 at 09:56:08AM +0200, Raimo Niskanen wrote:<br>
> On Tue, Sep 09, 2008 at 01:32:07PM +0200, Raimo Niskanen wrote:<br>
> > On Tue, Sep 09, 2008 at 06:47:25AM -0400, Edwin Fine wrote:<br>
> > > Raimo,<br>
> > ><br>
> > > Yes, it must be a port that is open in the firewall but have no listening<br>
> > > socket.<br>
> > > I have not tried it on other targets (I only have Windows and Linux, and I<br>
> > > tried connecting from Linux to Windows XP).<br>
> > ><br>
> > > Hope this helps.<br>
> ><br>
> > I can reproduce the bug on a SLES 10 SP 1 x86_64<br>
> > "Erlang (BEAM) emulator version 5.6.4 [source] [64-bit] [smp:4] [async-threads:0] [hipe] [kernel-poll:false]\n"<br>
> > both towards an XP machine and towards another SLES 10 machine,<br>
> > but oddly enough not against the machine itself neither over<br>
> > the loopback interface nor the external interface. It probably<br>
> > suggests badass timing is involved. I hope debug compiled<br>
> > still shows the symptom.<br>
> ><br>
> > I'll be back...<br>
> ><br>
><br>
> Well, it was not even a clear-cut problem.<br>
><br>
> It turned out to be a known problem. We ran into it a few months ago<br>
> and the solution then was to ignore the problem i.e workaround in<br>
> the testcases. It was assumed we had found a Linux kernel bug.<br>
><br>
> We do as supposed. If connect() for a non-blocking socket fails<br>
> with EINPROGRESS we put it in the poll() set and call poll().<br>
> Later poll() returns with POLLERR|POLLHUP on the socket.<br>
> We call getsockopt(,SOL_SOCKET,SO_ERROR,,) to check if<br>
> the connect succeeded, so far all is as in the manual, but sometimes<br>
> it succeeds but the socket is unusable. All recv() and sendmsg(),<br>
> etc fails.<br>
><br>
> The symptoms was also not that bad. Any subsequent usage of the<br>
> sockets fails, which a real application will have to be<br>
> prepared to anyway.<br>
><br>
> But taking a closer lock with strace reveals that we call<br>
> connect() in one thread, poll() in another and getsockopt()<br>
> in a third. Sometimes, and sometimes all in the same thread.<br>
> This task wanders between the schedulers in our SMP VM.<br>
><br>
> And when the problem starts it seems poll() returns with<br>
> POLLOUT|POLLHUP for the socket before we call connect()<br>
> in another thread, which is temporally impossible.<br>
> I have seen this in one strace and can not reproduce it.<br>
> while strace is running the bug does not show itself.<br>
><br>
> So, whe have the possibilites:<br>
> 1) A bug of ours where we mess up with the locking<br>
>    and loading of data for the poll set.<br>
> 2) A Linux kernel bug in this rare case of tossing<br>
>    the task between threads.<br>
> 3) An strace bug for SMP. Its view of the timeline<br>
>    is not necessarily correct.<br>
><br>
> I'll dig further.<br>
><br>
> I might write a small C program to try to provoke the Linux<br>
> kernel bug, and if it does not provoke it, it is our bug.<br>
><br>
<br>
Found the bug!<br>
<br>
It was a clear and simple bug in the TCP|UDP|SCTP/IP driver<br>
inet_drv, where making a connect, the poll set was changed<br>
first and then connect was called, and if connect did<br>
not give EINPROGRESS, the poll set was reset again.<br>
<br>
This is the wrong way to do it. The right is to change<br>
the poll set if you have to after getting EINPROGRESS.<br>
<br>
What happened now was:<br>
[thread 1]                      [thread 2]<br>
<br>
                                poll( ...<br>
socket() -> Socket<br>
Change pollset data<br>
write(InternalPipe)<br>
  to inform poll thread<br>
                                ...)poll -> internal pipe POLLIN|POLLRDNORM<br>
                                read(InternalPipe)<br>
connect(Socket, ...<br>
                                poll() -> Socket POLLOUT|POLLHUP<br>
... )connect -> EINPROGRESS<br>
                                getsockopt(Socket, SOL_SOCKET, SO_ERROR) -><br>
                                  no error<br>
<br>
Note that poll returns with ready for writing on Socket<br>
before connect returns with EINPROGRESS in the other<br>
thread, and Linus only knows why getsockopt() in this<br>
particular case returns no error.<br>
<br>
But we are mishandling the socket, that is for sure.<br>
Try this patch:<br>
*** /clearcase/otp/erts/erts/emulator/drivers/common/inet_drv.c@@/OTP_R12B-4    2008-09-01 14:51:18.000000000 +0200<br>
--- /clearcase/otp/erts/erts/emulator/drivers/common/inet_drv.c 2008-09-15 16:23:51.000000000 +0200<br>
***************<br>
*** 7239,7257 ****<br>
                             buf, &len) == NULL)<br>
            return ctl_error(EINVAL, rbuf, rsize);<br>
<br>
-       sock_select(INETP(desc), FD_CONNECT, 1);<br>
        code = sock_connect(desc->inet.s,<br>
                            (struct sockaddr*) &desc->inet.remote, len);<br>
        if ((code == SOCKET_ERROR) &&<br>
                ((sock_errno() == ERRNO_BLOCK) ||  /* Winsock2 */<br>
                 (sock_errno() == EINPROGRESS))) {      /* Unix & OSE!! */<br>
            desc->inet.state = TCP_STATE_CONNECTING;<br>
            if (timeout != INET_INFINITY)<br>
                driver_set_timer(desc->inet.port, timeout);<br>
            enq_async(INETP(desc), tbuf, INET_REQ_CONNECT);<br>
        }<br>
        else if (code == 0) { /* ok we are connected */<br>
-           sock_select(INETP(desc), FD_CONNECT, 0);<br>
            desc->inet.state = TCP_STATE_CONNECTED;<br>
            if (desc->inet.active)<br>
                sock_select(INETP(desc), (FD_READ|FD_CLOSE), 1);<br>
--- 7239,7256 ----<br>
                             buf, &len) == NULL)<br>
            return ctl_error(EINVAL, rbuf, rsize);<br>
<br>
        code = sock_connect(desc->inet.s,<br>
                            (struct sockaddr*) &desc->inet.remote, len);<br>
        if ((code == SOCKET_ERROR) &&<br>
                ((sock_errno() == ERRNO_BLOCK) ||  /* Winsock2 */<br>
                 (sock_errno() == EINPROGRESS))) {      /* Unix & OSE!! */<br>
+           sock_select(INETP(desc), FD_CONNECT, 1);<br>
            desc->inet.state = TCP_STATE_CONNECTING;<br>
            if (timeout != INET_INFINITY)<br>
                driver_set_timer(desc->inet.port, timeout);<br>
            enq_async(INETP(desc), tbuf, INET_REQ_CONNECT);<br>
        }<br>
        else if (code == 0) { /* ok we are connected */<br>
            desc->inet.state = TCP_STATE_CONNECTED;<br>
            if (desc->inet.active)<br>
                sock_select(INETP(desc), (FD_READ|FD_CLOSE), 1);<br>
***************<br>
*** 7259,7265 ****<br>
            async_ok(INETP(desc));<br>
        }<br>
        else {<br>
-           sock_select(INETP(desc), FD_CONNECT, 0);<br>
            return ctl_error(sock_errno(), rbuf, rsize);<br>
        }<br>
        return ctl_reply(INET_REP_OK, tbuf, 2, rbuf, rsize);<br>
--- 7258,7263 ----<br>
<br>
The patch has not been run through all our regression tests yet.<br>
<font color="#888888"><br>
--<br>
<br>
/ Raimo Niskanen, Erlang/OTP, Ericsson AB<br>
<br>
</font></blockquote></div><br></div>