crypto/tls: TLS client handshake is blocking incoming connections

[gopherbot]

by branimirkaradzic:

What steps will reproduce the problem?

 - Run http.ListenAndServeTLS server.
 - When connecting client, initiate TLS negotiation, but don't complete it. Client must not write nor close connection in order to reproduce this bug.


What is the expected output?

 - Server doesn't block processing incoming connections when negotiating TLS with client.
 - Server drops client after read/write timeout specified in http.Server struct.


What do you see instead?

Server becomes unresponsive.


Which compiler are you using (5g, 6g, 8g, gccgo)?

6g


Which operating system are you using?

Linux


Which revision are you using?  (hg identify)

b0819469a6df (release-branch.r60) release/release.r60


Please provide any additional information below.

N/A

[davecheney]

Comment 1:

Thanks, I tried your binary and it sigill'ed.
stora(~/devel) % gdb ./5.out 
GNU gdb (GDB) 7.3-debian
Copyright (C) 2011 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>;
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "arm-linux-gnueabi".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>;...
Reading symbols from /home/dfc/devel/5.out...(no debugging symbols found)...done.
(gdb) r
Starting program: /home/dfc/devel/5.out 
Program received signal SIGILL, Illegal instruction.
0x00030518 in math.init·1 ()
(gdb) x/i 0x00030518
=> 0x30518 <math.init·1+40>:    vmov.f64        d0, #112        ; 0x70
Can I ask you to check again that GOARM=5 is set before building ?

[bradfitz]

Comment 2:

Indeed.  I can reproduce this with telnet and curl.
In one window,
$ telnet camlistore.org 443
(and let it sit idle)
In the other window,
$ curl https://camlistore.org/
It hangs.  Leave it hanging.
Back in the telnet window, hit control-], q, <enter> and then the curl process
unblocks.
I think this explains why the camlistore website has been hanging every week or so,
always on https (and http works fine).
Last time camlistore hung, I sent it a SIGQUIT and noticed that the only weird thing was:
goroutine 6 [4]:
runtime.gosched+0x5c /home/camli/go/src/pkg/runtime/proc.c:603
        runtime.gosched()
runtime.chanrecv+0x177 /home/camli/go/src/pkg/runtime/chan.c:361
        runtime.chanrecv(0xf840160a20, 0x7fc9117ed7e8, 0x0, 0x0, 0x70100cff0, ...)
runtime.chanrecv1+0x4a /home/camli/go/src/pkg/runtime/chan.c:424
        runtime.chanrecv1(0xf840160a20, 0xf8400d2780)
net.*pollServer·WaitRead+0x49 /home/camli/go/src/pkg/net/fd.go:255
        net.*pollServer·WaitRead(0xf840021f80, 0xf8400d2780, 0x40000000400, 0xbffffffff)
net.*netFD·Read+0x1a4 /home/camli/go/src/pkg/net/fd.go:380
        net.*netFD·Read(0xf8400d2780, 0xf8402cc800, 0x40000000400, 0x0, 0x0, ...)
net.*TCPConn·Read+0x95 /home/camli/go/src/pkg/net/tcpsock.go:96
        net.*TCPConn·Read(0xf84019a638, 0xf8402cc800, 0x40000000400, 0x585638, 0x0, ...)
crypto/tls.*block·readFromUntil+0xa5 /home/camli/go/src/pkg/crypto/tls/conn.go:372
        crypto/tls.*block·readFromUntil(0xf84020c3a0, 0xf840144990, 0xf84019a638, 0xf800000005, 0xf84019a638, ...)
crypto/tls.*Conn·readRecord+0xf2 /home/camli/go/src/pkg/crypto/tls/conn.go:452
        crypto/tls.*Conn·readRecord(0xf840038380, 0xf800000016, 0xf840317750, 0xf8402a6800, 0x400000009, ...)
crypto/tls.*Conn·readHandshake+0x91 /home/camli/go/src/pkg/crypto/tls/conn.go:630
        crypto/tls.*Conn·readHandshake(0xf840038380, 0xf84019a616, 0xf84019a684, 0x4)
crypto/tls.*Conn·serverHandshake+0x119f
/home/camli/go/src/pkg/crypto/tls/handshake_server.go:200
        crypto/tls.*Conn·serverHandshake(0xf840038380, 0x0, 0x0, 0x0)
crypto/tls.*Conn·Handshake+0xfd /home/camli/go/src/pkg/crypto/tls/conn.go:756
        crypto/tls.*Conn·Handshake(0xf840038380, 0x0, 0x0, 0xf840038380)
http.newConn+0x1bd /home/camli/go/src/pkg/http/server.go:155
        http.newConn(0xf840147540, 0xf840038380, 0xf840045f60, 0xf840045f30, 0xf8401404b0, ...)
http.*Server·Serve+0x2d5 /home/camli/go/src/pkg/http/server.go:889
        http.*Server·Serve(0xf840012030, 0xf840142d40, 0xf840143c80, 0x0, 0x0, ...)
http.*Server·ListenAndServeTLS+0x29f /home/camli/go/src/pkg/http/server.go:996
        http.*Server·ListenAndServeTLS(0xf840012030, 0x7fff806973ac, 0x17, 0x7fff806973cd, 0x17, ...)
main._func_003+0x4a /home/camli/camlistore/website/camweb.go:330
        main._func_003(0xf840000658, 0xf840000488, 0x0, 0x0)
runtime.goexit /home/camli/go/src/pkg/runtime/proc.c:178
        runtime.goexit()
----- goroutine created by -----
main.main+0x1397 /home/camli/camlistore/website/camweb.go:331
That's probably related.

Owner changed to @bradfitz.

Status changed to Accepted.

[gopherbot]

Comment 3 by branimirkaradzic:

Hi Brad,
Yeah your stack trace shows it, but when you look at this code it's clear why it's
getting stuck. Probably solution is to use go routine to do tls handshake.
In pkg/http/server.go
func (srv *Server) Serve(l net.Listener) os.Error {
    ...
>>> c, err := srv.newConn(rw)
    if err != nil {
        continue
    }
    go c.serve()
func (srv *Server) newConn(rwc net.Conn) (c *conn, err os.Error) {
    ...
    if tlsConn, ok := rwc.(*tls.Conn); ok {
>>>     tlsConn.Handshake()
Until tlsConn.Handshake() is done, no new connections will be accepted.
Branimir

[rsc]

Comment 4:

Yes, what srv.newConn is doing has to be in the
goroutine that right now is just c.serve.

[bradfitz]

Comment 5:

Fixing coming up.

[bradfitz]

Comment 6:

http://golang.org/cl/5076042

[bradfitz]

Comment 7:

This issue was closed by revision 3c3a86c.

Status changed to Fixed.

[gopherbot]

Comment 8 by branimirkaradzic:

This fixes main issue when one client can make server unresponsive.
But handling timeout in tlsConn.Handshake() is still needed for SOMAXCONN clients case.
I haven't really reproduced this with default SOMAXCONN which is 128 in Go (see
listenBacklog), but the main bug was the same as case when SOMAXCONN is 1.
Thanks,
Branimir

[gopherbot]

Comment 9 by branimirkaradzic:

This fixes main issue when one client can make server unresponsive.
But handling timeout in tlsConn.Handshake() is still needed for SOMAXCONN clients case.
I haven't really reproduced this with default SOMAXCONN which is 128 in Go (see
listenBacklog), but the main bug was the same as case when SOMAXCONN is 1.
Thanks,
Branimir

[rsc]

Comment 10:

Why would that be?  All the TLS work has been moved
into background goroutines now.

[gopherbot]

Comment 11 by branimirkaradzic:

I'm thinking about malicious client case, when a lot of clients connect with telnet
(Brad's example above) and not process tls handshake negotiation. All goroutines will be
blocked in tls handshake, those clients won't be dropped because there is no timeout in
tls handshake. If enough malicious clients are connected at some point server will run
out of memory.

[rsc]

Comment 12:

Okay, but lots of simultaneous clients is not the same as SOMAXCONN.
SOMAXCONN is a limit on the number of pending connections
that haven't been Accepted yet.

[gopherbot]

Comment 13 by branimirkaradzic:

Yeah my bad I was thinking accept queue won't be freed until tls handshake is over, but
then after your message I realized code path will go back immediately into accept and
grab the next one.

[bradfitz]

Comment 14:

The problem is that readHandshake() in crypto/tls/conn.go is looping forever, even with
a timeout set.
I have a failing test.  Looking into the best fix.

[rsc]

Comment 15:

If tls is ignoring _any_ read error,
including EAGAIN, that's a bug and
should be fixed.