[erlang-bugs] : : : : Follow up: [BUG] gen_tcp:connect/3, 4 returns socket for closed port

[Raimo Niskanen]

On Mon, Sep 15, 2008 at 09:56:08AM +0200, Raimo Niskanen wrote:
> On Tue, Sep 09, 2008 at 01:32:07PM +0200, Raimo Niskanen wrote:
> > On Tue, Sep 09, 2008 at 06:47:25AM -0400, Edwin Fine wrote:
> > > Raimo,
> > > 
> > > Yes, it must be a port that is open in the firewall but have no listening
> > > socket.
> > > I have not tried it on other targets (I only have Windows and Linux, and I
> > > tried connecting from Linux to Windows XP).
> > > 
> > > Hope this helps.
> > 
> > I can reproduce the bug on a SLES 10 SP 1 x86_64 
> > "Erlang (BEAM) emulator version 5.6.4 [source] [64-bit] [smp:4] [async-threads:0] [hipe] [kernel-poll:false]\n"
> > both towards an XP machine and towards another SLES 10 machine,
> > but oddly enough not against the machine itself neither over
> > the loopback interface nor the external interface. It probably
> > suggests badass timing is involved. I hope debug compiled
> > still shows the symptom.
> > 
> > I'll be back...
> > 
> 
> Well, it was not even a clear-cut problem.
> 
> It turned out to be a known problem. We ran into it a few months ago
> and the solution then was to ignore the problem i.e workaround in
> the testcases. It was assumed we had found a Linux kernel bug.
> 
> We do as supposed. If connect() for a non-blocking socket fails
> with EINPROGRESS we put it in the poll() set and call poll().
> Later poll() returns with POLLERR|POLLHUP on the socket.
> We call getsockopt(,SOL_SOCKET,SO_ERROR,,) to check if
> the connect succeeded, so far all is as in the manual, but sometimes
> it succeeds but the socket is unusable. All recv() and sendmsg(),
> etc fails.
> 
> The symptoms was also not that bad. Any subsequent usage of the
> sockets fails, which a real application will have to be
> prepared to anyway.
> 
> But taking a closer lock with strace reveals that we call
> connect() in one thread, poll() in another and getsockopt()
> in a third. Sometimes, and sometimes all in the same thread.
> This task wanders between the schedulers in our SMP VM.
> 
> And when the problem starts it seems poll() returns with
> POLLOUT|POLLHUP for the socket before we call connect()
> in another thread, which is temporally impossible.
> I have seen this in one strace and can not reproduce it.
> while strace is running the bug does not show itself.
> 
> So, whe have the possibilites:
> 1) A bug of ours where we mess up with the locking
>    and loading of data for the poll set.
> 2) A Linux kernel bug in this rare case of tossing
>    the task between threads.
> 3) An strace bug for SMP. Its view of the timeline
>    is not necessarily correct.
> 
> I'll dig further.
> 
> I might write a small C program to try to provoke the Linux
> kernel bug, and if it does not provoke it, it is our bug.
> 

Found the bug!

It was a clear and simple bug in the TCP|UDP|SCTP/IP driver
inet_drv, where making a connect, the poll set was changed
first and then connect was called, and if connect did
not give EINPROGRESS, the poll set was reset again.

This is the wrong way to do it. The right is to change
the poll set if you have to after getting EINPROGRESS.

What happened now was:
[thread 1]			[thread 2]

				poll( ...
socket() -> Socket
Change pollset data
write(InternalPipe)
  to inform poll thread
				...)poll -> internal pipe POLLIN|POLLRDNORM
				read(InternalPipe)
connect(Socket, ...
				poll() -> Socket POLLOUT|POLLHUP
... )connect -> EINPROGRESS
				getsockopt(Socket, SOL_SOCKET, SO_ERROR) ->
				  no error

Note that poll returns with ready for writing on Socket
before connect returns with EINPROGRESS in the other
thread, and Linus only knows why getsockopt() in this
particular case returns no error.

But we are mishandling the socket, that is for sure.
Try this patch:
*** /clearcase/otp/erts/erts/emulator/drivers/common/inet_drv.c@@/OTP_R12B-4    2008-09-01 14:51:18.000000000 +0200
--- /clearcase/otp/erts/erts/emulator/drivers/common/inet_drv.c 2008-09-15 16:23:51.000000000 +0200
***************
*** 7239,7257 ****
                             buf, &len) == NULL)
            return ctl_error(EINVAL, rbuf, rsize);
  
-       sock_select(INETP(desc), FD_CONNECT, 1);
        code = sock_connect(desc->inet.s, 
                            (struct sockaddr*) &desc->inet.remote, len);
        if ((code == SOCKET_ERROR) && 
                ((sock_errno() == ERRNO_BLOCK) ||  /* Winsock2 */
                 (sock_errno() == EINPROGRESS))) {      /* Unix & OSE!! */
            desc->inet.state = TCP_STATE_CONNECTING;
            if (timeout != INET_INFINITY)
                driver_set_timer(desc->inet.port, timeout);
            enq_async(INETP(desc), tbuf, INET_REQ_CONNECT);
        }
        else if (code == 0) { /* ok we are connected */
-           sock_select(INETP(desc), FD_CONNECT, 0);
            desc->inet.state = TCP_STATE_CONNECTED;
            if (desc->inet.active)
                sock_select(INETP(desc), (FD_READ|FD_CLOSE), 1);
--- 7239,7256 ----
                             buf, &len) == NULL)
            return ctl_error(EINVAL, rbuf, rsize);
  
        code = sock_connect(desc->inet.s, 
                            (struct sockaddr*) &desc->inet.remote, len);
        if ((code == SOCKET_ERROR) && 
                ((sock_errno() == ERRNO_BLOCK) ||  /* Winsock2 */
                 (sock_errno() == EINPROGRESS))) {      /* Unix & OSE!! */
+           sock_select(INETP(desc), FD_CONNECT, 1);
            desc->inet.state = TCP_STATE_CONNECTING;
            if (timeout != INET_INFINITY)
                driver_set_timer(desc->inet.port, timeout);
            enq_async(INETP(desc), tbuf, INET_REQ_CONNECT);
        }
        else if (code == 0) { /* ok we are connected */
            desc->inet.state = TCP_STATE_CONNECTED;
            if (desc->inet.active)
                sock_select(INETP(desc), (FD_READ|FD_CLOSE), 1);
***************
*** 7259,7265 ****
            async_ok(INETP(desc));
        }
        else {
-           sock_select(INETP(desc), FD_CONNECT, 0);
            return ctl_error(sock_errno(), rbuf, rsize);
        }
        return ctl_reply(INET_REP_OK, tbuf, 2, rbuf, rsize);
--- 7258,7263 ----

The patch has not been run through all our regression tests yet.

-- 

/ Raimo Niskanen, Erlang/OTP, Ericsson AB